blob: c991566a1c57644a66e311792cba75e5f9236364 [file] [log] [blame]
jbates@chromium.org59c27602012-01-13 12:12:44 +09001// Copyright (c) 2012 The Chromium Authors. All rights reserved.
scheib@chromium.org603f46e2011-05-10 11:23:58 +09002// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
4
jbates@chromium.org5e2f67d2012-08-16 13:32:49 +09005#include "base/debug/trace_event_unittest.h"
scheib@chromium.org603f46e2011-05-10 11:23:58 +09006
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +09007#include <cstdlib>
8
scheib@chromium.org603f46e2011-05-10 11:23:58 +09009#include "base/bind.h"
10#include "base/command_line.h"
jbates@chromium.org5e2f67d2012-08-16 13:32:49 +090011#include "base/debug/trace_event.h"
scheib@chromium.org603f46e2011-05-10 11:23:58 +090012#include "base/json/json_reader.h"
13#include "base/json/json_writer.h"
jbates@chromium.org1f18e462011-09-07 02:56:24 +090014#include "base/memory/ref_counted_memory.h"
scheib@chromium.org603f46e2011-05-10 11:23:58 +090015#include "base/memory/scoped_ptr.h"
joth@chromium.org088ae012011-11-11 01:26:23 +090016#include "base/memory/singleton.h"
rsesek@chromium.org687756f2013-07-26 06:38:23 +090017#include "base/process/process_handle.h"
avi@chromium.org94bd5732013-06-11 22:36:37 +090018#include "base/strings/stringprintf.h"
scheib@chromium.org603f46e2011-05-10 11:23:58 +090019#include "base/synchronization/waitable_event.h"
joth@chromium.org088ae012011-11-11 01:26:23 +090020#include "base/threading/platform_thread.h"
scheib@chromium.org603f46e2011-05-10 11:23:58 +090021#include "base/threading/thread.h"
22#include "base/values.h"
23#include "testing/gmock/include/gmock/gmock.h"
24#include "testing/gtest/include/gtest/gtest.h"
25
jbates@chromium.org5e2f67d2012-08-16 13:32:49 +090026using base::debug::HighResSleepForTraceTest;
27
scheib@chromium.org603f46e2011-05-10 11:23:58 +090028namespace base {
29namespace debug {
30
31namespace {
32
jbates@chromium.org11d4c362011-09-13 07:03:41 +090033enum CompareOp {
34 IS_EQUAL,
35 IS_NOT_EQUAL,
36};
37
jbates@chromium.orgb3cab862011-05-14 08:30:35 +090038struct JsonKeyValue {
39 const char* key;
40 const char* value;
jbates@chromium.org11d4c362011-09-13 07:03:41 +090041 CompareOp op;
jbates@chromium.orgb3cab862011-05-14 08:30:35 +090042};
43
nduca@chromium.org3e5cb752013-05-04 23:28:07 +090044const int kThreadId = 42;
45const int kAsyncId = 5;
46const char kAsyncIdStr[] = "0x5";
47const int kAsyncId2 = 6;
48const char kAsyncId2Str[] = "0x6";
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +090049
scheib@chromium.org603f46e2011-05-10 11:23:58 +090050class TraceEventTestFixture : public testing::Test {
51 public:
ajwong@chromium.orgec1750a2011-06-27 01:22:50 +090052 void OnTraceDataCollected(
wangxianzhu@chromium.orgd787d4f2013-09-07 05:18:05 +090053 WaitableEvent* flush_complete_event,
54 const scoped_refptr<base::RefCountedString>& events_str,
55 bool has_more_events);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +090056 void OnTraceNotification(int notification) {
57 if (notification & TraceLog::EVENT_WATCH_NOTIFICATION)
58 ++event_watch_notification_;
jbroman@chromium.org4b3fba72013-08-13 12:06:42 +090059 notifications_received_ |= notification;
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +090060 }
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +090061 DictionaryValue* FindMatchingTraceEntry(const JsonKeyValue* key_values);
62 DictionaryValue* FindNamePhase(const char* name, const char* phase);
63 DictionaryValue* FindNamePhaseKeyValue(const char* name,
64 const char* phase,
65 const char* key,
66 const char* value);
jbates@chromium.org11d4c362011-09-13 07:03:41 +090067 bool FindMatchingValue(const char* key,
68 const char* value);
69 bool FindNonMatchingValue(const char* key,
70 const char* value);
71 void Clear() {
jbates@chromium.org11d4c362011-09-13 07:03:41 +090072 trace_parsed_.Clear();
jbates@chromium.org6a092d72011-10-25 01:34:08 +090073 json_output_.json_output.clear();
jbates@chromium.org11d4c362011-09-13 07:03:41 +090074 }
scheib@chromium.org603f46e2011-05-10 11:23:58 +090075
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +090076 void BeginTrace() {
dsinclair@chromium.org3f838632013-05-08 05:17:27 +090077 BeginSpecificTrace("*");
78 }
79
80 void BeginSpecificTrace(const std::string& filter) {
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +090081 event_watch_notification_ = 0;
caseq@google.com4cba9892013-04-29 18:08:28 +090082 notifications_received_ = 0;
dsinclair@chromium.org3f838632013-05-08 05:17:27 +090083 TraceLog::GetInstance()->SetEnabled(CategoryFilter(filter),
dsinclair@chromium.orga7fb8d62013-02-23 11:09:53 +090084 TraceLog::RECORD_UNTIL_FULL);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +090085 }
86
87 void EndTraceAndFlush() {
wangxianzhu@chromium.orgd787d4f2013-09-07 05:18:05 +090088 WaitableEvent flush_complete_event(false, false);
89 EndTraceAndFlushAsync(&flush_complete_event);
90 flush_complete_event.Wait();
91 }
92
93 void EndTraceAndFlushAsync(WaitableEvent* flush_complete_event) {
caseq@google.comedcf6262013-01-16 20:41:57 +090094 while (TraceLog::GetInstance()->IsEnabled())
95 TraceLog::GetInstance()->SetDisabled();
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +090096 TraceLog::GetInstance()->Flush(
97 base::Bind(&TraceEventTestFixture::OnTraceDataCollected,
wangxianzhu@chromium.orgd787d4f2013-09-07 05:18:05 +090098 base::Unretained(static_cast<TraceEventTestFixture*>(this)),
99 base::Unretained(flush_complete_event)));
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +0900100 }
101
haraken@chromium.org1722fea2013-10-08 10:01:25 +0900102 void FlushMonitoring() {
103 WaitableEvent flush_complete_event(false, false);
104 FlushMonitoring(&flush_complete_event);
105 flush_complete_event.Wait();
106 }
107
108 void FlushMonitoring(WaitableEvent* flush_complete_event) {
109 TraceLog::GetInstance()->FlushButLeaveBufferIntact(
110 base::Bind(&TraceEventTestFixture::OnTraceDataCollected,
111 base::Unretained(static_cast<TraceEventTestFixture*>(this)),
112 base::Unretained(flush_complete_event)));
113 }
114
rsleevi@chromium.orgde3a6cf2012-04-06 12:53:02 +0900115 virtual void SetUp() OVERRIDE {
dsinclair@chromium.org38608f82013-01-26 05:41:19 +0900116 const char* name = PlatformThread::GetName();
117 old_thread_name_ = name ? strdup(name) : NULL;
caseq@google.com4bdbd862013-04-29 21:22:48 +0900118 notifications_received_ = 0;
jam@chromium.orga15c6772013-07-09 08:26:14 +0900119
120 TraceLog::DeleteForTesting();
121 TraceLog* tracelog = TraceLog::GetInstance();
122 ASSERT_TRUE(tracelog);
123 ASSERT_FALSE(tracelog->IsEnabled());
124 tracelog->SetNotificationCallback(
125 base::Bind(&TraceEventTestFixture::OnTraceNotification,
126 base::Unretained(this)));
127 trace_buffer_.SetOutputCallback(json_output_.GetCallback());
joth@chromium.org088ae012011-11-11 01:26:23 +0900128 }
rsleevi@chromium.orgde3a6cf2012-04-06 12:53:02 +0900129 virtual void TearDown() OVERRIDE {
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900130 if (TraceLog::GetInstance())
131 EXPECT_FALSE(TraceLog::GetInstance()->IsEnabled());
dsinclair@chromium.org38608f82013-01-26 05:41:19 +0900132 PlatformThread::SetName(old_thread_name_ ? old_thread_name_ : "");
133 free(old_thread_name_);
134 old_thread_name_ = NULL;
jam@chromium.orga15c6772013-07-09 08:26:14 +0900135 // We want our singleton torn down after each test.
136 TraceLog::DeleteForTesting();
joth@chromium.org088ae012011-11-11 01:26:23 +0900137 }
138
dsinclair@chromium.org38608f82013-01-26 05:41:19 +0900139 char* old_thread_name_;
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900140 ListValue trace_parsed_;
jbates@chromium.org6a092d72011-10-25 01:34:08 +0900141 base::debug::TraceResultBuffer trace_buffer_;
142 base::debug::TraceResultBuffer::SimpleOutput json_output_;
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +0900143 int event_watch_notification_;
caseq@google.com4cba9892013-04-29 18:08:28 +0900144 int notifications_received_;
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900145
146 private:
147 // We want our singleton torn down after each test.
148 ShadowingAtExitManager at_exit_manager_;
jbates@chromium.orgb84db522011-10-04 02:51:25 +0900149 Lock lock_;
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900150};
151
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900152void TraceEventTestFixture::OnTraceDataCollected(
wangxianzhu@chromium.orgd787d4f2013-09-07 05:18:05 +0900153 WaitableEvent* flush_complete_event,
154 const scoped_refptr<base::RefCountedString>& events_str,
155 bool has_more_events) {
jbates@chromium.orgb84db522011-10-04 02:51:25 +0900156 AutoLock lock(lock_);
jbates@chromium.org6a092d72011-10-25 01:34:08 +0900157 json_output_.json_output.clear();
158 trace_buffer_.Start();
husky@chromium.org3b366292012-02-24 13:17:06 +0900159 trace_buffer_.AddFragment(events_str->data());
jbates@chromium.org6a092d72011-10-25 01:34:08 +0900160 trace_buffer_.Finish();
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900161
162 scoped_ptr<Value> root;
rsesek@chromium.orgc2d2b202012-05-17 00:23:30 +0900163 root.reset(base::JSONReader::Read(json_output_.json_output,
164 JSON_PARSE_RFC | JSON_DETACHABLE_CHILDREN));
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900165
jbates@chromium.org59c27602012-01-13 12:12:44 +0900166 if (!root.get()) {
167 LOG(ERROR) << json_output_.json_output;
168 }
169
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900170 ListValue* root_list = NULL;
171 ASSERT_TRUE(root.get());
172 ASSERT_TRUE(root->GetAsList(&root_list));
173
174 // Move items into our aggregate collection
175 while (root_list->GetSize()) {
bauerb@chromium.orgae43e0a2013-08-06 22:33:04 +0900176 scoped_ptr<Value> item;
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900177 root_list->Remove(0, &item);
bauerb@chromium.orgae43e0a2013-08-06 22:33:04 +0900178 trace_parsed_.Append(item.release());
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900179 }
wangxianzhu@chromium.orgd787d4f2013-09-07 05:18:05 +0900180
181 if (!has_more_events)
182 flush_complete_event->Signal();
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900183}
184
jbates@chromium.org11d4c362011-09-13 07:03:41 +0900185static bool CompareJsonValues(const std::string& lhs,
186 const std::string& rhs,
187 CompareOp op) {
188 switch (op) {
189 case IS_EQUAL:
190 return lhs == rhs;
191 case IS_NOT_EQUAL:
192 return lhs != rhs;
193 default:
194 CHECK(0);
195 }
196 return false;
197}
198
jbates@chromium.orgb3cab862011-05-14 08:30:35 +0900199static bool IsKeyValueInDict(const JsonKeyValue* key_value,
200 DictionaryValue* dict) {
201 Value* value = NULL;
202 std::string value_str;
203 if (dict->Get(key_value->key, &value) &&
204 value->GetAsString(&value_str) &&
jbates@chromium.org11d4c362011-09-13 07:03:41 +0900205 CompareJsonValues(value_str, key_value->value, key_value->op))
jbates@chromium.orgb3cab862011-05-14 08:30:35 +0900206 return true;
207
208 // Recurse to test arguments
209 DictionaryValue* args_dict = NULL;
210 dict->GetDictionary("args", &args_dict);
211 if (args_dict)
212 return IsKeyValueInDict(key_value, args_dict);
213
214 return false;
215}
216
217static bool IsAllKeyValueInDict(const JsonKeyValue* key_values,
218 DictionaryValue* dict) {
219 // Scan all key_values, they must all be present and equal.
220 while (key_values && key_values->key) {
221 if (!IsKeyValueInDict(key_values, dict))
222 return false;
223 ++key_values;
224 }
225 return true;
226}
227
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +0900228DictionaryValue* TraceEventTestFixture::FindMatchingTraceEntry(
jbates@chromium.orgb3cab862011-05-14 08:30:35 +0900229 const JsonKeyValue* key_values) {
230 // Scan all items
231 size_t trace_parsed_count = trace_parsed_.GetSize();
232 for (size_t i = 0; i < trace_parsed_count; i++) {
233 Value* value = NULL;
234 trace_parsed_.Get(i, &value);
235 if (!value || value->GetType() != Value::TYPE_DICTIONARY)
236 continue;
237 DictionaryValue* dict = static_cast<DictionaryValue*>(value);
238
239 if (IsAllKeyValueInDict(key_values, dict))
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +0900240 return dict;
jbates@chromium.orgb3cab862011-05-14 08:30:35 +0900241 }
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +0900242 return NULL;
jbates@chromium.orgb3cab862011-05-14 08:30:35 +0900243}
244
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +0900245DictionaryValue* TraceEventTestFixture::FindNamePhase(const char* name,
246 const char* phase) {
jbates@chromium.orgb3cab862011-05-14 08:30:35 +0900247 JsonKeyValue key_values[] = {
jbates@chromium.org11d4c362011-09-13 07:03:41 +0900248 {"name", name, IS_EQUAL},
249 {"ph", phase, IS_EQUAL},
250 {0, 0, IS_EQUAL}
251 };
252 return FindMatchingTraceEntry(key_values);
253}
254
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +0900255DictionaryValue* TraceEventTestFixture::FindNamePhaseKeyValue(
256 const char* name,
257 const char* phase,
258 const char* key,
259 const char* value) {
260 JsonKeyValue key_values[] = {
261 {"name", name, IS_EQUAL},
262 {"ph", phase, IS_EQUAL},
263 {key, value, IS_EQUAL},
264 {0, 0, IS_EQUAL}
265 };
266 return FindMatchingTraceEntry(key_values);
267}
268
jbates@chromium.org11d4c362011-09-13 07:03:41 +0900269bool TraceEventTestFixture::FindMatchingValue(const char* key,
270 const char* value) {
271 JsonKeyValue key_values[] = {
272 {key, value, IS_EQUAL},
273 {0, 0, IS_EQUAL}
274 };
275 return FindMatchingTraceEntry(key_values);
276}
277
278bool TraceEventTestFixture::FindNonMatchingValue(const char* key,
279 const char* value) {
280 JsonKeyValue key_values[] = {
281 {key, value, IS_NOT_EQUAL},
282 {0, 0, IS_EQUAL}
jbates@chromium.orgb3cab862011-05-14 08:30:35 +0900283 };
284 return FindMatchingTraceEntry(key_values);
285}
286
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +0900287bool IsStringInDict(const char* string_to_match, const DictionaryValue* dict) {
pneubeck@chromium.orga2fbefc2013-01-18 23:43:27 +0900288 for (DictionaryValue::Iterator it(*dict); !it.IsAtEnd(); it.Advance()) {
289 if (it.key().find(string_to_match) != std::string::npos)
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900290 return true;
291
292 std::string value_str;
pneubeck@chromium.orga2fbefc2013-01-18 23:43:27 +0900293 it.value().GetAsString(&value_str);
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900294 if (value_str.find(string_to_match) != std::string::npos)
295 return true;
296 }
297
298 // Recurse to test arguments
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +0900299 const DictionaryValue* args_dict = NULL;
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900300 dict->GetDictionary("args", &args_dict);
301 if (args_dict)
302 return IsStringInDict(string_to_match, args_dict);
303
304 return false;
305}
306
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +0900307const DictionaryValue* FindTraceEntry(
308 const ListValue& trace_parsed,
309 const char* string_to_match,
310 const DictionaryValue* match_after_this_item = NULL) {
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900311 // Scan all items
312 size_t trace_parsed_count = trace_parsed.GetSize();
313 for (size_t i = 0; i < trace_parsed_count; i++) {
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +0900314 const Value* value = NULL;
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900315 trace_parsed.Get(i, &value);
316 if (match_after_this_item) {
317 if (value == match_after_this_item)
318 match_after_this_item = NULL;
319 continue;
320 }
321 if (!value || value->GetType() != Value::TYPE_DICTIONARY)
322 continue;
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +0900323 const DictionaryValue* dict = static_cast<const DictionaryValue*>(value);
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900324
325 if (IsStringInDict(string_to_match, dict))
326 return dict;
327 }
328 return NULL;
329}
330
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +0900331std::vector<const DictionaryValue*> FindTraceEntries(
nduca@chromium.org6d048772011-08-10 00:16:25 +0900332 const ListValue& trace_parsed,
333 const char* string_to_match) {
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +0900334 std::vector<const DictionaryValue*> hits;
nduca@chromium.org6d048772011-08-10 00:16:25 +0900335 size_t trace_parsed_count = trace_parsed.GetSize();
336 for (size_t i = 0; i < trace_parsed_count; i++) {
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +0900337 const Value* value = NULL;
nduca@chromium.org6d048772011-08-10 00:16:25 +0900338 trace_parsed.Get(i, &value);
339 if (!value || value->GetType() != Value::TYPE_DICTIONARY)
340 continue;
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +0900341 const DictionaryValue* dict = static_cast<const DictionaryValue*>(value);
nduca@chromium.org6d048772011-08-10 00:16:25 +0900342
343 if (IsStringInDict(string_to_match, dict))
344 hits.push_back(dict);
345 }
346 return hits;
347}
348
349void TraceWithAllMacroVariants(WaitableEvent* task_complete_event) {
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900350 {
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +0900351 TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW call", 0x1122, "extrastring1");
352 TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW call", 0x3344, "extrastring2");
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900353 TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW call",
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +0900354 0x5566, "extrastring3");
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900355
356 TRACE_EVENT0("all", "TRACE_EVENT0 call");
357 TRACE_EVENT1("all", "TRACE_EVENT1 call", "name1", "value1");
358 TRACE_EVENT2("all", "TRACE_EVENT2 call",
jbates@chromium.org788d5a12011-09-07 09:43:11 +0900359 "name1", "\"value1\"",
360 "name2", "value\\2");
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900361
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +0900362 TRACE_EVENT_INSTANT0("all", "TRACE_EVENT_INSTANT0 call",
363 TRACE_EVENT_SCOPE_GLOBAL);
364 TRACE_EVENT_INSTANT1("all", "TRACE_EVENT_INSTANT1 call",
365 TRACE_EVENT_SCOPE_PROCESS, "name1", "value1");
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900366 TRACE_EVENT_INSTANT2("all", "TRACE_EVENT_INSTANT2 call",
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +0900367 TRACE_EVENT_SCOPE_THREAD,
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900368 "name1", "value1",
369 "name2", "value2");
370
371 TRACE_EVENT_BEGIN0("all", "TRACE_EVENT_BEGIN0 call");
372 TRACE_EVENT_BEGIN1("all", "TRACE_EVENT_BEGIN1 call", "name1", "value1");
373 TRACE_EVENT_BEGIN2("all", "TRACE_EVENT_BEGIN2 call",
374 "name1", "value1",
375 "name2", "value2");
376
377 TRACE_EVENT_END0("all", "TRACE_EVENT_END0 call");
378 TRACE_EVENT_END1("all", "TRACE_EVENT_END1 call", "name1", "value1");
379 TRACE_EVENT_END2("all", "TRACE_EVENT_END2 call",
380 "name1", "value1",
381 "name2", "value2");
nduca@chromium.org62210b02011-11-18 18:36:36 +0900382
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900383 TRACE_EVENT_ASYNC_BEGIN0("all", "TRACE_EVENT_ASYNC_BEGIN0 call", kAsyncId);
384 TRACE_EVENT_ASYNC_BEGIN1("all", "TRACE_EVENT_ASYNC_BEGIN1 call", kAsyncId,
jbates@chromium.org88295f92012-03-01 12:04:59 +0900385 "name1", "value1");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900386 TRACE_EVENT_ASYNC_BEGIN2("all", "TRACE_EVENT_ASYNC_BEGIN2 call", kAsyncId,
jbates@chromium.org88295f92012-03-01 12:04:59 +0900387 "name1", "value1",
388 "name2", "value2");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900389
jbates@chromium.orgbd9d20a2012-09-11 14:56:05 +0900390 TRACE_EVENT_ASYNC_STEP0("all", "TRACE_EVENT_ASYNC_STEP0 call",
simonjam@chromium.org87d003c2012-03-28 09:14:11 +0900391 5, "step1");
jbates@chromium.orgbd9d20a2012-09-11 14:56:05 +0900392 TRACE_EVENT_ASYNC_STEP1("all", "TRACE_EVENT_ASYNC_STEP1 call",
simonjam@chromium.org87d003c2012-03-28 09:14:11 +0900393 5, "step2", "name1", "value1");
jbates@chromium.org88295f92012-03-01 12:04:59 +0900394
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900395 TRACE_EVENT_ASYNC_END0("all", "TRACE_EVENT_ASYNC_END0 call", kAsyncId);
396 TRACE_EVENT_ASYNC_END1("all", "TRACE_EVENT_ASYNC_END1 call", kAsyncId,
jbates@chromium.org88295f92012-03-01 12:04:59 +0900397 "name1", "value1");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900398 TRACE_EVENT_ASYNC_END2("all", "TRACE_EVENT_ASYNC_END2 call", kAsyncId,
jbates@chromium.org88295f92012-03-01 12:04:59 +0900399 "name1", "value1",
400 "name2", "value2");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900401
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900402 TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW0 call", kAsyncId, NULL);
403 TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW1 call", kAsyncId, "value");
404 TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW0 call", kAsyncId, NULL);
405 TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW1 call", kAsyncId, "value");
406 TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW0 call", kAsyncId, NULL);
407 TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW1 call", kAsyncId, "value");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900408
nduca@chromium.org62210b02011-11-18 18:36:36 +0900409 TRACE_COUNTER1("all", "TRACE_COUNTER1 call", 31415);
410 TRACE_COUNTER2("all", "TRACE_COUNTER2 call",
411 "a", 30000,
412 "b", 1415);
piman@chromium.org902b2952011-12-16 10:19:06 +0900413
414 TRACE_COUNTER_ID1("all", "TRACE_COUNTER_ID1 call", 0x319009, 31415);
415 TRACE_COUNTER_ID2("all", "TRACE_COUNTER_ID2 call", 0x319009,
416 "a", 30000, "b", 1415);
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900417
418 TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP0("all",
419 "TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP0 call",
420 kAsyncId, kThreadId, 12345);
421 TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP0("all",
422 "TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP0 call",
423 kAsyncId, kThreadId, 23456);
424
425 TRACE_EVENT_BEGIN_WITH_ID_TID_AND_TIMESTAMP0("all",
426 "TRACE_EVENT_BEGIN_WITH_ID_TID_AND_TIMESTAMP0 call",
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900427 kAsyncId2, kThreadId, 34567);
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900428 TRACE_EVENT_END_WITH_ID_TID_AND_TIMESTAMP0("all",
429 "TRACE_EVENT_END_WITH_ID_TID_AND_TIMESTAMP0 call",
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900430 kAsyncId2, kThreadId, 45678);
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900431
caseq@google.coma88a9c52013-02-26 23:33:33 +0900432 TRACE_EVENT_OBJECT_CREATED_WITH_ID("all", "tracked object 1", 0x42);
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900433 TRACE_EVENT_OBJECT_SNAPSHOT_WITH_ID(
434 "all", "tracked object 1", 0x42, "hello");
caseq@google.coma88a9c52013-02-26 23:33:33 +0900435 TRACE_EVENT_OBJECT_DELETED_WITH_ID("all", "tracked object 1", 0x42);
436
437 TraceScopedTrackableObject<int> trackable("all", "tracked object 2",
438 0x2128506);
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900439 trackable.snapshot("world");
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900440 } // Scope close causes TRACE_EVENT0 etc to send their END events.
441
442 if (task_complete_event)
443 task_complete_event->Signal();
444}
445
jbates@chromium.org6a092d72011-10-25 01:34:08 +0900446void ValidateAllTraceMacrosCreatedData(const ListValue& trace_parsed) {
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +0900447 const DictionaryValue* item = NULL;
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900448
449#define EXPECT_FIND_(string) \
jbates@chromium.orgb84db522011-10-04 02:51:25 +0900450 EXPECT_TRUE((item = FindTraceEntry(trace_parsed, string)));
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900451#define EXPECT_NOT_FIND_(string) \
jbates@chromium.orgb84db522011-10-04 02:51:25 +0900452 EXPECT_FALSE((item = FindTraceEntry(trace_parsed, string)));
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900453#define EXPECT_SUB_FIND_(string) \
jbates@chromium.orgb84db522011-10-04 02:51:25 +0900454 if (item) EXPECT_TRUE((IsStringInDict(string, item)));
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900455
456 EXPECT_FIND_("ETW Trace Event");
457 EXPECT_FIND_("all");
458 EXPECT_FIND_("TRACE_EVENT_BEGIN_ETW call");
459 {
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +0900460 std::string str_val;
461 EXPECT_TRUE(item && item->GetString("args.id", &str_val));
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900462 EXPECT_STREQ("0x1122", str_val.c_str());
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900463 }
464 EXPECT_SUB_FIND_("extrastring1");
465 EXPECT_FIND_("TRACE_EVENT_END_ETW call");
466 EXPECT_FIND_("TRACE_EVENT_INSTANT_ETW call");
467 EXPECT_FIND_("TRACE_EVENT0 call");
468 {
wangxianzhu@chromium.orgf17afbd2013-10-21 12:51:13 +0900469 std::string ph;
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900470 std::string ph_end;
471 EXPECT_TRUE((item = FindTraceEntry(trace_parsed, "TRACE_EVENT0 call")));
wangxianzhu@chromium.orgf17afbd2013-10-21 12:51:13 +0900472 EXPECT_TRUE((item && item->GetString("ph", &ph)));
473 EXPECT_EQ("X", ph);
474 EXPECT_FALSE((item = FindTraceEntry(trace_parsed, "TRACE_EVENT0 call",
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900475 item)));
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900476 }
477 EXPECT_FIND_("TRACE_EVENT1 call");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900478 EXPECT_SUB_FIND_("name1");
479 EXPECT_SUB_FIND_("value1");
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900480 EXPECT_FIND_("TRACE_EVENT2 call");
481 EXPECT_SUB_FIND_("name1");
jbates@chromium.org788d5a12011-09-07 09:43:11 +0900482 EXPECT_SUB_FIND_("\"value1\"");
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900483 EXPECT_SUB_FIND_("name2");
jbates@chromium.org788d5a12011-09-07 09:43:11 +0900484 EXPECT_SUB_FIND_("value\\2");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900485
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900486 EXPECT_FIND_("TRACE_EVENT_INSTANT0 call");
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +0900487 {
488 std::string scope;
489 EXPECT_TRUE((item && item->GetString("s", &scope)));
490 EXPECT_EQ("g", scope);
491 }
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900492 EXPECT_FIND_("TRACE_EVENT_INSTANT1 call");
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +0900493 {
494 std::string scope;
495 EXPECT_TRUE((item && item->GetString("s", &scope)));
496 EXPECT_EQ("p", scope);
497 }
jbates@chromium.org59c27602012-01-13 12:12:44 +0900498 EXPECT_SUB_FIND_("name1");
499 EXPECT_SUB_FIND_("value1");
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900500 EXPECT_FIND_("TRACE_EVENT_INSTANT2 call");
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +0900501 {
502 std::string scope;
503 EXPECT_TRUE((item && item->GetString("s", &scope)));
504 EXPECT_EQ("t", scope);
505 }
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900506 EXPECT_SUB_FIND_("name1");
507 EXPECT_SUB_FIND_("value1");
508 EXPECT_SUB_FIND_("name2");
509 EXPECT_SUB_FIND_("value2");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900510
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900511 EXPECT_FIND_("TRACE_EVENT_BEGIN0 call");
512 EXPECT_FIND_("TRACE_EVENT_BEGIN1 call");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900513 EXPECT_SUB_FIND_("name1");
514 EXPECT_SUB_FIND_("value1");
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900515 EXPECT_FIND_("TRACE_EVENT_BEGIN2 call");
516 EXPECT_SUB_FIND_("name1");
517 EXPECT_SUB_FIND_("value1");
518 EXPECT_SUB_FIND_("name2");
519 EXPECT_SUB_FIND_("value2");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900520
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900521 EXPECT_FIND_("TRACE_EVENT_END0 call");
522 EXPECT_FIND_("TRACE_EVENT_END1 call");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900523 EXPECT_SUB_FIND_("name1");
524 EXPECT_SUB_FIND_("value1");
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900525 EXPECT_FIND_("TRACE_EVENT_END2 call");
526 EXPECT_SUB_FIND_("name1");
527 EXPECT_SUB_FIND_("value1");
528 EXPECT_SUB_FIND_("name2");
529 EXPECT_SUB_FIND_("value2");
nduca@chromium.org62210b02011-11-18 18:36:36 +0900530
jbates@chromium.org88295f92012-03-01 12:04:59 +0900531 EXPECT_FIND_("TRACE_EVENT_ASYNC_BEGIN0 call");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900532 EXPECT_SUB_FIND_("id");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900533 EXPECT_SUB_FIND_(kAsyncIdStr);
jbates@chromium.org88295f92012-03-01 12:04:59 +0900534 EXPECT_FIND_("TRACE_EVENT_ASYNC_BEGIN1 call");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900535 EXPECT_SUB_FIND_("id");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900536 EXPECT_SUB_FIND_(kAsyncIdStr);
jbates@chromium.org59c27602012-01-13 12:12:44 +0900537 EXPECT_SUB_FIND_("name1");
538 EXPECT_SUB_FIND_("value1");
jbates@chromium.org88295f92012-03-01 12:04:59 +0900539 EXPECT_FIND_("TRACE_EVENT_ASYNC_BEGIN2 call");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900540 EXPECT_SUB_FIND_("id");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900541 EXPECT_SUB_FIND_(kAsyncIdStr);
jbates@chromium.org59c27602012-01-13 12:12:44 +0900542 EXPECT_SUB_FIND_("name1");
543 EXPECT_SUB_FIND_("value1");
544 EXPECT_SUB_FIND_("name2");
545 EXPECT_SUB_FIND_("value2");
546
jbates@chromium.orgbd9d20a2012-09-11 14:56:05 +0900547 EXPECT_FIND_("TRACE_EVENT_ASYNC_STEP0 call");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900548 EXPECT_SUB_FIND_("id");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900549 EXPECT_SUB_FIND_(kAsyncIdStr);
simonjam@chromium.org87d003c2012-03-28 09:14:11 +0900550 EXPECT_SUB_FIND_("step1");
jbates@chromium.orgbd9d20a2012-09-11 14:56:05 +0900551 EXPECT_FIND_("TRACE_EVENT_ASYNC_STEP1 call");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900552 EXPECT_SUB_FIND_("id");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900553 EXPECT_SUB_FIND_(kAsyncIdStr);
simonjam@chromium.org87d003c2012-03-28 09:14:11 +0900554 EXPECT_SUB_FIND_("step2");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900555 EXPECT_SUB_FIND_("name1");
556 EXPECT_SUB_FIND_("value1");
jbates@chromium.org88295f92012-03-01 12:04:59 +0900557
558 EXPECT_FIND_("TRACE_EVENT_ASYNC_END0 call");
559 EXPECT_SUB_FIND_("id");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900560 EXPECT_SUB_FIND_(kAsyncIdStr);
jbates@chromium.org88295f92012-03-01 12:04:59 +0900561 EXPECT_FIND_("TRACE_EVENT_ASYNC_END1 call");
562 EXPECT_SUB_FIND_("id");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900563 EXPECT_SUB_FIND_(kAsyncIdStr);
jbates@chromium.org88295f92012-03-01 12:04:59 +0900564 EXPECT_SUB_FIND_("name1");
565 EXPECT_SUB_FIND_("value1");
566 EXPECT_FIND_("TRACE_EVENT_ASYNC_END2 call");
jbates@chromium.org59c27602012-01-13 12:12:44 +0900567 EXPECT_SUB_FIND_("id");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900568 EXPECT_SUB_FIND_(kAsyncIdStr);
jbates@chromium.org59c27602012-01-13 12:12:44 +0900569 EXPECT_SUB_FIND_("name1");
570 EXPECT_SUB_FIND_("value1");
571 EXPECT_SUB_FIND_("name2");
572 EXPECT_SUB_FIND_("value2");
573
574 EXPECT_FIND_("TRACE_EVENT_BEGIN_ETW0 call");
575 EXPECT_SUB_FIND_("id");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900576 EXPECT_SUB_FIND_(kAsyncIdStr);
jbates@chromium.org59c27602012-01-13 12:12:44 +0900577 EXPECT_SUB_FIND_("extra");
578 EXPECT_SUB_FIND_("NULL");
579 EXPECT_FIND_("TRACE_EVENT_BEGIN_ETW1 call");
580 EXPECT_SUB_FIND_("id");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900581 EXPECT_SUB_FIND_(kAsyncIdStr);
jbates@chromium.org59c27602012-01-13 12:12:44 +0900582 EXPECT_SUB_FIND_("extra");
583 EXPECT_SUB_FIND_("value");
584 EXPECT_FIND_("TRACE_EVENT_END_ETW0 call");
585 EXPECT_SUB_FIND_("id");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900586 EXPECT_SUB_FIND_(kAsyncIdStr);
jbates@chromium.org59c27602012-01-13 12:12:44 +0900587 EXPECT_SUB_FIND_("extra");
588 EXPECT_SUB_FIND_("NULL");
589 EXPECT_FIND_("TRACE_EVENT_END_ETW1 call");
590 EXPECT_SUB_FIND_("id");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900591 EXPECT_SUB_FIND_(kAsyncIdStr);
jbates@chromium.org59c27602012-01-13 12:12:44 +0900592 EXPECT_SUB_FIND_("extra");
593 EXPECT_SUB_FIND_("value");
594 EXPECT_FIND_("TRACE_EVENT_INSTANT_ETW0 call");
595 EXPECT_SUB_FIND_("id");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900596 EXPECT_SUB_FIND_(kAsyncIdStr);
jbates@chromium.org59c27602012-01-13 12:12:44 +0900597 EXPECT_SUB_FIND_("extra");
598 EXPECT_SUB_FIND_("NULL");
599 EXPECT_FIND_("TRACE_EVENT_INSTANT_ETW1 call");
600 EXPECT_SUB_FIND_("id");
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900601 EXPECT_SUB_FIND_(kAsyncIdStr);
jbates@chromium.org59c27602012-01-13 12:12:44 +0900602 EXPECT_SUB_FIND_("extra");
603 EXPECT_SUB_FIND_("value");
604
nduca@chromium.org62210b02011-11-18 18:36:36 +0900605 EXPECT_FIND_("TRACE_COUNTER1 call");
606 {
607 std::string ph;
608 EXPECT_TRUE((item && item->GetString("ph", &ph)));
609 EXPECT_EQ("C", ph);
610
611 int value;
612 EXPECT_TRUE((item && item->GetInteger("args.value", &value)));
613 EXPECT_EQ(31415, value);
614 }
615
616 EXPECT_FIND_("TRACE_COUNTER2 call");
617 {
618 std::string ph;
619 EXPECT_TRUE((item && item->GetString("ph", &ph)));
620 EXPECT_EQ("C", ph);
621
622 int value;
623 EXPECT_TRUE((item && item->GetInteger("args.a", &value)));
624 EXPECT_EQ(30000, value);
625
626 EXPECT_TRUE((item && item->GetInteger("args.b", &value)));
627 EXPECT_EQ(1415, value);
628 }
629
piman@chromium.org902b2952011-12-16 10:19:06 +0900630 EXPECT_FIND_("TRACE_COUNTER_ID1 call");
631 {
632 std::string id;
633 EXPECT_TRUE((item && item->GetString("id", &id)));
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900634 EXPECT_EQ("0x319009", id);
piman@chromium.org902b2952011-12-16 10:19:06 +0900635
636 std::string ph;
637 EXPECT_TRUE((item && item->GetString("ph", &ph)));
638 EXPECT_EQ("C", ph);
639
640 int value;
641 EXPECT_TRUE((item && item->GetInteger("args.value", &value)));
642 EXPECT_EQ(31415, value);
643 }
644
645 EXPECT_FIND_("TRACE_COUNTER_ID2 call");
646 {
647 std::string id;
648 EXPECT_TRUE((item && item->GetString("id", &id)));
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900649 EXPECT_EQ("0x319009", id);
piman@chromium.org902b2952011-12-16 10:19:06 +0900650
651 std::string ph;
652 EXPECT_TRUE((item && item->GetString("ph", &ph)));
653 EXPECT_EQ("C", ph);
654
655 int value;
656 EXPECT_TRUE((item && item->GetInteger("args.a", &value)));
657 EXPECT_EQ(30000, value);
658
659 EXPECT_TRUE((item && item->GetInteger("args.b", &value)));
660 EXPECT_EQ(1415, value);
661 }
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900662
663 EXPECT_FIND_("TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP0 call");
664 {
665 int val;
666 EXPECT_TRUE((item && item->GetInteger("ts", &val)));
667 EXPECT_EQ(12345, val);
668 EXPECT_TRUE((item && item->GetInteger("tid", &val)));
669 EXPECT_EQ(kThreadId, val);
670 std::string id;
671 EXPECT_TRUE((item && item->GetString("id", &id)));
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900672 EXPECT_EQ(kAsyncIdStr, id);
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900673 }
674
675 EXPECT_FIND_("TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP0 call");
676 {
677 int val;
678 EXPECT_TRUE((item && item->GetInteger("ts", &val)));
679 EXPECT_EQ(23456, val);
680 EXPECT_TRUE((item && item->GetInteger("tid", &val)));
681 EXPECT_EQ(kThreadId, val);
682 std::string id;
683 EXPECT_TRUE((item && item->GetString("id", &id)));
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900684 EXPECT_EQ(kAsyncIdStr, id);
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900685 }
686
687 EXPECT_FIND_("TRACE_EVENT_BEGIN_WITH_ID_TID_AND_TIMESTAMP0 call");
688 {
689 int val;
690 EXPECT_TRUE((item && item->GetInteger("ts", &val)));
691 EXPECT_EQ(34567, val);
692 EXPECT_TRUE((item && item->GetInteger("tid", &val)));
693 EXPECT_EQ(kThreadId, val);
694 std::string id;
695 EXPECT_TRUE((item && item->GetString("id", &id)));
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900696 EXPECT_EQ(kAsyncId2Str, id);
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900697 }
698
699 EXPECT_FIND_("TRACE_EVENT_END_WITH_ID_TID_AND_TIMESTAMP0 call");
700 {
701 int val;
702 EXPECT_TRUE((item && item->GetInteger("ts", &val)));
703 EXPECT_EQ(45678, val);
704 EXPECT_TRUE((item && item->GetInteger("tid", &val)));
705 EXPECT_EQ(kThreadId, val);
706 std::string id;
707 EXPECT_TRUE((item && item->GetString("id", &id)));
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900708 EXPECT_EQ(kAsyncId2Str, id);
dsinclair@chromium.org9aed8362013-02-16 03:58:25 +0900709 }
caseq@google.coma88a9c52013-02-26 23:33:33 +0900710
711 EXPECT_FIND_("tracked object 1");
712 {
713 std::string phase;
714 std::string id;
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900715 std::string snapshot;
caseq@google.coma88a9c52013-02-26 23:33:33 +0900716
717 EXPECT_TRUE((item && item->GetString("ph", &phase)));
718 EXPECT_EQ("N", phase);
719 EXPECT_TRUE((item && item->GetString("id", &id)));
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900720 EXPECT_EQ("0x42", id);
721
722 item = FindTraceEntry(trace_parsed, "tracked object 1", item);
723 EXPECT_TRUE(item);
724 EXPECT_TRUE(item && item->GetString("ph", &phase));
725 EXPECT_EQ("O", phase);
726 EXPECT_TRUE(item && item->GetString("id", &id));
727 EXPECT_EQ("0x42", id);
728 EXPECT_TRUE(item && item->GetString("args.snapshot", &snapshot));
729 EXPECT_EQ("hello", snapshot);
730
731 item = FindTraceEntry(trace_parsed, "tracked object 1", item);
732 EXPECT_TRUE(item);
733 EXPECT_TRUE(item && item->GetString("ph", &phase));
caseq@google.coma88a9c52013-02-26 23:33:33 +0900734 EXPECT_EQ("D", phase);
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900735 EXPECT_TRUE(item && item->GetString("id", &id));
736 EXPECT_EQ("0x42", id);
caseq@google.coma88a9c52013-02-26 23:33:33 +0900737 }
738
739 EXPECT_FIND_("tracked object 2");
740 {
741 std::string phase;
742 std::string id;
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900743 std::string snapshot;
caseq@google.coma88a9c52013-02-26 23:33:33 +0900744
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900745 EXPECT_TRUE(item && item->GetString("ph", &phase));
caseq@google.coma88a9c52013-02-26 23:33:33 +0900746 EXPECT_EQ("N", phase);
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900747 EXPECT_TRUE(item && item->GetString("id", &id));
748 EXPECT_EQ("0x2128506", id);
749
750 item = FindTraceEntry(trace_parsed, "tracked object 2", item);
751 EXPECT_TRUE(item);
752 EXPECT_TRUE(item && item->GetString("ph", &phase));
753 EXPECT_EQ("O", phase);
754 EXPECT_TRUE(item && item->GetString("id", &id));
755 EXPECT_EQ("0x2128506", id);
756 EXPECT_TRUE(item && item->GetString("args.snapshot", &snapshot));
757 EXPECT_EQ("world", snapshot);
758
759 item = FindTraceEntry(trace_parsed, "tracked object 2", item);
760 EXPECT_TRUE(item);
761 EXPECT_TRUE(item && item->GetString("ph", &phase));
caseq@google.coma88a9c52013-02-26 23:33:33 +0900762 EXPECT_EQ("D", phase);
nduca@chromium.org3e5cb752013-05-04 23:28:07 +0900763 EXPECT_TRUE(item && item->GetString("id", &id));
764 EXPECT_EQ("0x2128506", id);
caseq@google.coma88a9c52013-02-26 23:33:33 +0900765 }
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900766}
767
nduca@chromium.org6d048772011-08-10 00:16:25 +0900768void TraceManyInstantEvents(int thread_id, int num_events,
jbates@chromium.org6a092d72011-10-25 01:34:08 +0900769 WaitableEvent* task_complete_event) {
nduca@chromium.org6d048772011-08-10 00:16:25 +0900770 for (int i = 0; i < num_events; i++) {
771 TRACE_EVENT_INSTANT2("all", "multi thread event",
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +0900772 TRACE_EVENT_SCOPE_THREAD,
nduca@chromium.org6d048772011-08-10 00:16:25 +0900773 "thread", thread_id,
774 "event", i);
775 }
776
777 if (task_complete_event)
778 task_complete_event->Signal();
779}
780
781void ValidateInstantEventPresentOnEveryThread(const ListValue& trace_parsed,
jbates@chromium.org6a092d72011-10-25 01:34:08 +0900782 int num_threads,
783 int num_events) {
nduca@chromium.org6d048772011-08-10 00:16:25 +0900784 std::map<int, std::map<int, bool> > results;
785
786 size_t trace_parsed_count = trace_parsed.GetSize();
787 for (size_t i = 0; i < trace_parsed_count; i++) {
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +0900788 const Value* value = NULL;
nduca@chromium.org6d048772011-08-10 00:16:25 +0900789 trace_parsed.Get(i, &value);
790 if (!value || value->GetType() != Value::TYPE_DICTIONARY)
791 continue;
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +0900792 const DictionaryValue* dict = static_cast<const DictionaryValue*>(value);
nduca@chromium.org6d048772011-08-10 00:16:25 +0900793 std::string name;
794 dict->GetString("name", &name);
795 if (name != "multi thread event")
796 continue;
797
798 int thread = 0;
799 int event = 0;
800 EXPECT_TRUE(dict->GetInteger("args.thread", &thread));
801 EXPECT_TRUE(dict->GetInteger("args.event", &event));
802 results[thread][event] = true;
803 }
804
805 EXPECT_FALSE(results[-1][-1]);
806 for (int thread = 0; thread < num_threads; thread++) {
807 for (int event = 0; event < num_events; event++) {
808 EXPECT_TRUE(results[thread][event]);
809 }
810 }
811}
812
813void TraceCallsWithCachedCategoryPointersPointers(const char* name_str) {
814 TRACE_EVENT0("category name1", name_str);
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +0900815 TRACE_EVENT_INSTANT0("category name2", name_str, TRACE_EVENT_SCOPE_THREAD);
nduca@chromium.org6d048772011-08-10 00:16:25 +0900816 TRACE_EVENT_BEGIN0("category name3", name_str);
817 TRACE_EVENT_END0("category name4", name_str);
818}
819
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900820} // namespace
821
jbates@chromium.org5e2f67d2012-08-16 13:32:49 +0900822void HighResSleepForTraceTest(base::TimeDelta elapsed) {
823 base::TimeTicks end_time = base::TimeTicks::HighResNow() + elapsed;
824 do {
825 base::PlatformThread::Sleep(base::TimeDelta::FromMilliseconds(1));
826 } while (base::TimeTicks::HighResNow() < end_time);
827}
828
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900829// Simple Test for emitting data and validating it was received.
830TEST_F(TraceEventTestFixture, DataCaptured) {
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +0900831 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"),
832 TraceLog::RECORD_UNTIL_FULL);
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900833
nduca@chromium.org6d048772011-08-10 00:16:25 +0900834 TraceWithAllMacroVariants(NULL);
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900835
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +0900836 EndTraceAndFlush();
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900837
jbates@chromium.org6a092d72011-10-25 01:34:08 +0900838 ValidateAllTraceMacrosCreatedData(trace_parsed_);
scheib@chromium.org603f46e2011-05-10 11:23:58 +0900839}
840
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900841class MockEnabledStateChangedObserver :
jamescook@chromium.orgd25d76b2013-06-14 02:44:56 +0900842 public base::debug::TraceLog::EnabledStateObserver {
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900843 public:
jamescook@chromium.orgd25d76b2013-06-14 02:44:56 +0900844 MOCK_METHOD0(OnTraceLogEnabled, void());
845 MOCK_METHOD0(OnTraceLogDisabled, void());
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900846};
847
848TEST_F(TraceEventTestFixture, EnabledObserverFiresOnEnable) {
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900849 MockEnabledStateChangedObserver observer;
850 TraceLog::GetInstance()->AddEnabledStateObserver(&observer);
851
jamescook@chromium.orgd25d76b2013-06-14 02:44:56 +0900852 EXPECT_CALL(observer, OnTraceLogEnabled())
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900853 .Times(1);
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +0900854 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"),
855 TraceLog::RECORD_UNTIL_FULL);
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900856 testing::Mock::VerifyAndClear(&observer);
jamescook@chromium.orgd25d76b2013-06-14 02:44:56 +0900857 EXPECT_TRUE(TraceLog::GetInstance()->IsEnabled());
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900858
859 // Cleanup.
860 TraceLog::GetInstance()->RemoveEnabledStateObserver(&observer);
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +0900861 TraceLog::GetInstance()->SetDisabled();
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900862}
863
864TEST_F(TraceEventTestFixture, EnabledObserverDoesntFireOnSecondEnable) {
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +0900865 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"),
866 TraceLog::RECORD_UNTIL_FULL);
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900867
868 testing::StrictMock<MockEnabledStateChangedObserver> observer;
869 TraceLog::GetInstance()->AddEnabledStateObserver(&observer);
870
jamescook@chromium.orgd25d76b2013-06-14 02:44:56 +0900871 EXPECT_CALL(observer, OnTraceLogEnabled())
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900872 .Times(0);
jamescook@chromium.orgd25d76b2013-06-14 02:44:56 +0900873 EXPECT_CALL(observer, OnTraceLogDisabled())
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900874 .Times(0);
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +0900875 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"),
876 TraceLog::RECORD_UNTIL_FULL);
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900877 testing::Mock::VerifyAndClear(&observer);
jamescook@chromium.orgd25d76b2013-06-14 02:44:56 +0900878 EXPECT_TRUE(TraceLog::GetInstance()->IsEnabled());
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900879
880 // Cleanup.
881 TraceLog::GetInstance()->RemoveEnabledStateObserver(&observer);
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +0900882 TraceLog::GetInstance()->SetDisabled();
883 TraceLog::GetInstance()->SetDisabled();
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900884}
885
caseq@google.comedcf6262013-01-16 20:41:57 +0900886TEST_F(TraceEventTestFixture, EnabledObserverDoesntFireOnNestedDisable) {
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +0900887 CategoryFilter cf_inc_all("*");
888 TraceLog::GetInstance()->SetEnabled(cf_inc_all, TraceLog::RECORD_UNTIL_FULL);
889 TraceLog::GetInstance()->SetEnabled(cf_inc_all, TraceLog::RECORD_UNTIL_FULL);
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900890
891 testing::StrictMock<MockEnabledStateChangedObserver> observer;
892 TraceLog::GetInstance()->AddEnabledStateObserver(&observer);
893
jamescook@chromium.orgd25d76b2013-06-14 02:44:56 +0900894 EXPECT_CALL(observer, OnTraceLogEnabled())
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900895 .Times(0);
jamescook@chromium.orgd25d76b2013-06-14 02:44:56 +0900896 EXPECT_CALL(observer, OnTraceLogDisabled())
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900897 .Times(0);
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +0900898 TraceLog::GetInstance()->SetDisabled();
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900899 testing::Mock::VerifyAndClear(&observer);
900
901 // Cleanup.
902 TraceLog::GetInstance()->RemoveEnabledStateObserver(&observer);
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +0900903 TraceLog::GetInstance()->SetDisabled();
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900904}
905
906TEST_F(TraceEventTestFixture, EnabledObserverFiresOnDisable) {
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +0900907 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"),
908 TraceLog::RECORD_UNTIL_FULL);
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900909
910 MockEnabledStateChangedObserver observer;
911 TraceLog::GetInstance()->AddEnabledStateObserver(&observer);
912
jamescook@chromium.orgd25d76b2013-06-14 02:44:56 +0900913 EXPECT_CALL(observer, OnTraceLogDisabled())
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900914 .Times(1);
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +0900915 TraceLog::GetInstance()->SetDisabled();
nduca@chromium.org6a7360c2012-02-20 15:35:15 +0900916 testing::Mock::VerifyAndClear(&observer);
917
918 // Cleanup.
919 TraceLog::GetInstance()->RemoveEnabledStateObserver(&observer);
920}
921
jamescook@chromium.orgd25d76b2013-06-14 02:44:56 +0900922// Tests the IsEnabled() state of TraceLog changes before callbacks.
923class AfterStateChangeEnabledStateObserver
924 : public base::debug::TraceLog::EnabledStateObserver {
925 public:
926 AfterStateChangeEnabledStateObserver() {}
927 virtual ~AfterStateChangeEnabledStateObserver() {}
928
929 // base::debug::TraceLog::EnabledStateObserver overrides:
930 virtual void OnTraceLogEnabled() OVERRIDE {
931 EXPECT_TRUE(TraceLog::GetInstance()->IsEnabled());
932 }
933
934 virtual void OnTraceLogDisabled() OVERRIDE {
935 EXPECT_FALSE(TraceLog::GetInstance()->IsEnabled());
936 }
937};
938
939TEST_F(TraceEventTestFixture, ObserversFireAfterStateChange) {
jamescook@chromium.orgd25d76b2013-06-14 02:44:56 +0900940 AfterStateChangeEnabledStateObserver observer;
941 TraceLog::GetInstance()->AddEnabledStateObserver(&observer);
942
943 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"),
944 TraceLog::RECORD_UNTIL_FULL);
945 EXPECT_TRUE(TraceLog::GetInstance()->IsEnabled());
946
947 TraceLog::GetInstance()->SetDisabled();
948 EXPECT_FALSE(TraceLog::GetInstance()->IsEnabled());
949
950 TraceLog::GetInstance()->RemoveEnabledStateObserver(&observer);
951}
952
953// Tests that a state observer can remove itself during a callback.
954class SelfRemovingEnabledStateObserver
955 : public base::debug::TraceLog::EnabledStateObserver {
956 public:
957 SelfRemovingEnabledStateObserver() {}
958 virtual ~SelfRemovingEnabledStateObserver() {}
959
960 // base::debug::TraceLog::EnabledStateObserver overrides:
961 virtual void OnTraceLogEnabled() OVERRIDE {}
962
963 virtual void OnTraceLogDisabled() OVERRIDE {
964 TraceLog::GetInstance()->RemoveEnabledStateObserver(this);
965 }
966};
967
968TEST_F(TraceEventTestFixture, SelfRemovingObserver) {
jamescook@chromium.orgd25d76b2013-06-14 02:44:56 +0900969 ASSERT_EQ(0u, TraceLog::GetInstance()->GetObserverCountForTest());
970
971 SelfRemovingEnabledStateObserver observer;
972 TraceLog::GetInstance()->AddEnabledStateObserver(&observer);
973 EXPECT_EQ(1u, TraceLog::GetInstance()->GetObserverCountForTest());
974
975 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"),
976 TraceLog::RECORD_UNTIL_FULL);
977 TraceLog::GetInstance()->SetDisabled();
978 // The observer removed itself on disable.
979 EXPECT_EQ(0u, TraceLog::GetInstance()->GetObserverCountForTest());
980}
981
nduca@chromium.orgcb323952013-06-04 10:31:52 +0900982bool IsNewTrace() {
983 bool is_new_trace;
984 TRACE_EVENT_IS_NEW_TRACE(&is_new_trace);
985 return is_new_trace;
986}
987
988TEST_F(TraceEventTestFixture, NewTraceRecording) {
nduca@chromium.orgcb323952013-06-04 10:31:52 +0900989 ASSERT_FALSE(IsNewTrace());
990 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"),
991 TraceLog::RECORD_UNTIL_FULL);
992 // First call to IsNewTrace() should succeed. But, the second shouldn't.
993 ASSERT_TRUE(IsNewTrace());
994 ASSERT_FALSE(IsNewTrace());
995 EndTraceAndFlush();
996
997 // IsNewTrace() should definitely be false now.
998 ASSERT_FALSE(IsNewTrace());
999
1000 // Start another trace. IsNewTrace() should become true again, briefly, as
1001 // before.
1002 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"),
1003 TraceLog::RECORD_UNTIL_FULL);
1004 ASSERT_TRUE(IsNewTrace());
1005 ASSERT_FALSE(IsNewTrace());
1006
1007 // Cleanup.
1008 EndTraceAndFlush();
1009}
1010
1011
jbates@chromium.org11d4c362011-09-13 07:03:41 +09001012// Test that categories work.
1013TEST_F(TraceEventTestFixture, Categories) {
jbates@chromium.org11d4c362011-09-13 07:03:41 +09001014 // Test that categories that are used can be retrieved whether trace was
1015 // enabled or disabled when the trace event was encountered.
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001016 TRACE_EVENT_INSTANT0("c1", "name", TRACE_EVENT_SCOPE_THREAD);
1017 TRACE_EVENT_INSTANT0("c2", "name", TRACE_EVENT_SCOPE_THREAD);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001018 BeginTrace();
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001019 TRACE_EVENT_INSTANT0("c3", "name", TRACE_EVENT_SCOPE_THREAD);
1020 TRACE_EVENT_INSTANT0("c4", "name", TRACE_EVENT_SCOPE_THREAD);
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001021 // Category groups containing more than one category.
1022 TRACE_EVENT_INSTANT0("c5,c6", "name", TRACE_EVENT_SCOPE_THREAD);
1023 TRACE_EVENT_INSTANT0("c7,c8", "name", TRACE_EVENT_SCOPE_THREAD);
dsinclair@chromium.org3f838632013-05-08 05:17:27 +09001024 TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("c9"), "name",
1025 TRACE_EVENT_SCOPE_THREAD);
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001026
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001027 EndTraceAndFlush();
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001028 std::vector<std::string> cat_groups;
1029 TraceLog::GetInstance()->GetKnownCategoryGroups(&cat_groups);
1030 EXPECT_TRUE(std::find(cat_groups.begin(),
1031 cat_groups.end(), "c1") != cat_groups.end());
1032 EXPECT_TRUE(std::find(cat_groups.begin(),
1033 cat_groups.end(), "c2") != cat_groups.end());
1034 EXPECT_TRUE(std::find(cat_groups.begin(),
1035 cat_groups.end(), "c3") != cat_groups.end());
1036 EXPECT_TRUE(std::find(cat_groups.begin(),
1037 cat_groups.end(), "c4") != cat_groups.end());
1038 EXPECT_TRUE(std::find(cat_groups.begin(),
1039 cat_groups.end(), "c5,c6") != cat_groups.end());
1040 EXPECT_TRUE(std::find(cat_groups.begin(),
1041 cat_groups.end(), "c7,c8") != cat_groups.end());
dsinclair@chromium.org3f838632013-05-08 05:17:27 +09001042 EXPECT_TRUE(std::find(cat_groups.begin(),
1043 cat_groups.end(),
1044 "disabled-by-default-c9") != cat_groups.end());
dsinclair@chromium.orgc61f1842013-04-20 06:29:21 +09001045 // Make sure metadata isn't returned.
1046 EXPECT_TRUE(std::find(cat_groups.begin(),
1047 cat_groups.end(), "__metadata") == cat_groups.end());
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001048
jbates@chromium.org11d4c362011-09-13 07:03:41 +09001049 const std::vector<std::string> empty_categories;
1050 std::vector<std::string> included_categories;
1051 std::vector<std::string> excluded_categories;
1052
1053 // Test that category filtering works.
1054
1055 // Include nonexistent category -> no events
1056 Clear();
1057 included_categories.clear();
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001058 TraceLog::GetInstance()->SetEnabled(CategoryFilter("not_found823564786"),
dsinclair@chromium.orga7fb8d62013-02-23 11:09:53 +09001059 TraceLog::RECORD_UNTIL_FULL);
junov@chromium.org5daaa152013-08-17 04:02:53 +09001060 TRACE_EVENT_INSTANT0("cat1", "name", TRACE_EVENT_SCOPE_THREAD);
1061 TRACE_EVENT_INSTANT0("cat2", "name", TRACE_EVENT_SCOPE_THREAD);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001062 EndTraceAndFlush();
junov@chromium.org5daaa152013-08-17 04:02:53 +09001063 EXPECT_TRUE(trace_parsed_.empty());
jbates@chromium.org11d4c362011-09-13 07:03:41 +09001064
1065 // Include existent category -> only events of that category
1066 Clear();
1067 included_categories.clear();
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001068 TraceLog::GetInstance()->SetEnabled(CategoryFilter("inc"),
dsinclair@chromium.orga7fb8d62013-02-23 11:09:53 +09001069 TraceLog::RECORD_UNTIL_FULL);
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001070 TRACE_EVENT_INSTANT0("inc", "name", TRACE_EVENT_SCOPE_THREAD);
1071 TRACE_EVENT_INSTANT0("inc2", "name", TRACE_EVENT_SCOPE_THREAD);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001072 EndTraceAndFlush();
jbates@chromium.org11d4c362011-09-13 07:03:41 +09001073 EXPECT_TRUE(FindMatchingValue("cat", "inc"));
junov@chromium.org5daaa152013-08-17 04:02:53 +09001074 EXPECT_FALSE(FindNonMatchingValue("cat", "inc"));
jbates@chromium.org11d4c362011-09-13 07:03:41 +09001075
1076 // Include existent wildcard -> all categories matching wildcard
1077 Clear();
1078 included_categories.clear();
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001079 TraceLog::GetInstance()->SetEnabled(
1080 CategoryFilter("inc_wildcard_*,inc_wildchar_?_end"),
1081 TraceLog::RECORD_UNTIL_FULL);
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001082 TRACE_EVENT_INSTANT0("inc_wildcard_abc", "included",
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001083 TRACE_EVENT_SCOPE_THREAD);
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001084 TRACE_EVENT_INSTANT0("inc_wildcard_", "included", TRACE_EVENT_SCOPE_THREAD);
1085 TRACE_EVENT_INSTANT0("inc_wildchar_x_end", "included",
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001086 TRACE_EVENT_SCOPE_THREAD);
junov@chromium.org5daaa152013-08-17 04:02:53 +09001087 TRACE_EVENT_INSTANT0("inc_wildchar_bla_end", "not_inc",
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001088 TRACE_EVENT_SCOPE_THREAD);
junov@chromium.org5daaa152013-08-17 04:02:53 +09001089 TRACE_EVENT_INSTANT0("cat1", "not_inc", TRACE_EVENT_SCOPE_THREAD);
1090 TRACE_EVENT_INSTANT0("cat2", "not_inc", TRACE_EVENT_SCOPE_THREAD);
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001091 TRACE_EVENT_INSTANT0("inc_wildcard_category,other_category", "included",
1092 TRACE_EVENT_SCOPE_THREAD);
1093 TRACE_EVENT_INSTANT0(
1094 "non_included_category,inc_wildcard_category", "included",
1095 TRACE_EVENT_SCOPE_THREAD);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001096 EndTraceAndFlush();
jbates@chromium.org11d4c362011-09-13 07:03:41 +09001097 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildcard_abc"));
1098 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildcard_"));
1099 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildchar_x_end"));
junov@chromium.org5daaa152013-08-17 04:02:53 +09001100 EXPECT_FALSE(FindMatchingValue("name", "not_inc"));
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001101 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildcard_category,other_category"));
1102 EXPECT_TRUE(FindMatchingValue("cat",
1103 "non_included_category,inc_wildcard_category"));
jbates@chromium.org11d4c362011-09-13 07:03:41 +09001104
1105 included_categories.clear();
1106
1107 // Exclude nonexistent category -> all events
1108 Clear();
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001109 TraceLog::GetInstance()->SetEnabled(CategoryFilter("-not_found823564786"),
dsinclair@chromium.orga7fb8d62013-02-23 11:09:53 +09001110 TraceLog::RECORD_UNTIL_FULL);
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001111 TRACE_EVENT_INSTANT0("cat1", "name", TRACE_EVENT_SCOPE_THREAD);
1112 TRACE_EVENT_INSTANT0("cat2", "name", TRACE_EVENT_SCOPE_THREAD);
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001113 TRACE_EVENT_INSTANT0("category1,category2", "name", TRACE_EVENT_SCOPE_THREAD);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001114 EndTraceAndFlush();
jbates@chromium.org11d4c362011-09-13 07:03:41 +09001115 EXPECT_TRUE(FindMatchingValue("cat", "cat1"));
1116 EXPECT_TRUE(FindMatchingValue("cat", "cat2"));
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001117 EXPECT_TRUE(FindMatchingValue("cat", "category1,category2"));
jbates@chromium.org11d4c362011-09-13 07:03:41 +09001118
1119 // Exclude existent category -> only events of other categories
1120 Clear();
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001121 TraceLog::GetInstance()->SetEnabled(CategoryFilter("-inc"),
dsinclair@chromium.orga7fb8d62013-02-23 11:09:53 +09001122 TraceLog::RECORD_UNTIL_FULL);
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001123 TRACE_EVENT_INSTANT0("inc", "name", TRACE_EVENT_SCOPE_THREAD);
1124 TRACE_EVENT_INSTANT0("inc2", "name", TRACE_EVENT_SCOPE_THREAD);
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001125 TRACE_EVENT_INSTANT0("inc2,inc", "name", TRACE_EVENT_SCOPE_THREAD);
1126 TRACE_EVENT_INSTANT0("inc,inc2", "name", TRACE_EVENT_SCOPE_THREAD);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001127 EndTraceAndFlush();
jbates@chromium.org11d4c362011-09-13 07:03:41 +09001128 EXPECT_TRUE(FindMatchingValue("cat", "inc2"));
1129 EXPECT_FALSE(FindMatchingValue("cat", "inc"));
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001130 EXPECT_FALSE(FindMatchingValue("cat", "inc2,inc"));
1131 EXPECT_FALSE(FindMatchingValue("cat", "inc,inc2"));
jbates@chromium.org11d4c362011-09-13 07:03:41 +09001132
1133 // Exclude existent wildcard -> all categories not matching wildcard
1134 Clear();
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001135 TraceLog::GetInstance()->SetEnabled(
1136 CategoryFilter("-inc_wildcard_*,-inc_wildchar_?_end"),
1137 TraceLog::RECORD_UNTIL_FULL);
junov@chromium.org5daaa152013-08-17 04:02:53 +09001138 TRACE_EVENT_INSTANT0("inc_wildcard_abc", "not_inc",
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001139 TRACE_EVENT_SCOPE_THREAD);
1140 TRACE_EVENT_INSTANT0("inc_wildcard_", "not_inc",
1141 TRACE_EVENT_SCOPE_THREAD);
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001142 TRACE_EVENT_INSTANT0("inc_wildchar_x_end", "not_inc",
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001143 TRACE_EVENT_SCOPE_THREAD);
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001144 TRACE_EVENT_INSTANT0("inc_wildchar_bla_end", "included",
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001145 TRACE_EVENT_SCOPE_THREAD);
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001146 TRACE_EVENT_INSTANT0("cat1", "included", TRACE_EVENT_SCOPE_THREAD);
1147 TRACE_EVENT_INSTANT0("cat2", "included", TRACE_EVENT_SCOPE_THREAD);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001148 EndTraceAndFlush();
jbates@chromium.org11d4c362011-09-13 07:03:41 +09001149 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildchar_bla_end"));
1150 EXPECT_TRUE(FindMatchingValue("cat", "cat1"));
1151 EXPECT_TRUE(FindMatchingValue("cat", "cat2"));
1152 EXPECT_FALSE(FindMatchingValue("name", "not_inc"));
1153}
1154
jbates@chromium.orgb3cab862011-05-14 08:30:35 +09001155
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001156// Test EVENT_WATCH_NOTIFICATION
1157TEST_F(TraceEventTestFixture, EventWatchNotification) {
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001158 // Basic one occurrence.
1159 BeginTrace();
1160 TraceLog::GetInstance()->SetWatchEvent("cat", "event");
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001161 TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001162 EndTraceAndFlush();
1163 EXPECT_EQ(event_watch_notification_, 1);
1164
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001165 // Auto-reset after end trace.
1166 BeginTrace();
1167 TraceLog::GetInstance()->SetWatchEvent("cat", "event");
1168 EndTraceAndFlush();
1169 BeginTrace();
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001170 TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001171 EndTraceAndFlush();
1172 EXPECT_EQ(event_watch_notification_, 0);
1173
1174 // Multiple occurrence.
1175 BeginTrace();
1176 int num_occurrences = 5;
1177 TraceLog::GetInstance()->SetWatchEvent("cat", "event");
1178 for (int i = 0; i < num_occurrences; ++i)
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001179 TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001180 EndTraceAndFlush();
1181 EXPECT_EQ(event_watch_notification_, num_occurrences);
1182
1183 // Wrong category.
1184 BeginTrace();
1185 TraceLog::GetInstance()->SetWatchEvent("cat", "event");
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001186 TRACE_EVENT_INSTANT0("wrong_cat", "event", TRACE_EVENT_SCOPE_THREAD);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001187 EndTraceAndFlush();
1188 EXPECT_EQ(event_watch_notification_, 0);
1189
1190 // Wrong name.
1191 BeginTrace();
1192 TraceLog::GetInstance()->SetWatchEvent("cat", "event");
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001193 TRACE_EVENT_INSTANT0("cat", "wrong_event", TRACE_EVENT_SCOPE_THREAD);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001194 EndTraceAndFlush();
1195 EXPECT_EQ(event_watch_notification_, 0);
1196
1197 // Canceled.
1198 BeginTrace();
1199 TraceLog::GetInstance()->SetWatchEvent("cat", "event");
1200 TraceLog::GetInstance()->CancelWatchEvent();
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001201 TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001202 EndTraceAndFlush();
1203 EXPECT_EQ(event_watch_notification_, 0);
1204}
1205
jbates@chromium.org88295f92012-03-01 12:04:59 +09001206// Test ASYNC_BEGIN/END events
1207TEST_F(TraceEventTestFixture, AsyncBeginEndEvents) {
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001208 BeginTrace();
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +09001209
1210 unsigned long long id = 0xfeedbeeffeedbeefull;
jbates@chromium.org88295f92012-03-01 12:04:59 +09001211 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name1", id);
jbates@chromium.orgbd9d20a2012-09-11 14:56:05 +09001212 TRACE_EVENT_ASYNC_STEP0( "cat", "name1", id, "step1");
jbates@chromium.org88295f92012-03-01 12:04:59 +09001213 TRACE_EVENT_ASYNC_END0("cat", "name1", id);
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +09001214 TRACE_EVENT_BEGIN0( "cat", "name2");
jbates@chromium.org88295f92012-03-01 12:04:59 +09001215 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name3", 0);
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +09001216
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001217 EndTraceAndFlush();
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +09001218
1219 EXPECT_TRUE(FindNamePhase("name1", "S"));
jbates@chromium.org88295f92012-03-01 12:04:59 +09001220 EXPECT_TRUE(FindNamePhase("name1", "T"));
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +09001221 EXPECT_TRUE(FindNamePhase("name1", "F"));
1222
1223 std::string id_str;
nduca@chromium.org3e5cb752013-05-04 23:28:07 +09001224 StringAppendF(&id_str, "0x%llx", id);
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +09001225
1226 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "S", "id", id_str.c_str()));
jbates@chromium.org88295f92012-03-01 12:04:59 +09001227 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "T", "id", id_str.c_str()));
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +09001228 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "F", "id", id_str.c_str()));
nduca@chromium.org3e5cb752013-05-04 23:28:07 +09001229 EXPECT_TRUE(FindNamePhaseKeyValue("name3", "S", "id", "0x0"));
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +09001230
1231 // BEGIN events should not have id
1232 EXPECT_FALSE(FindNamePhaseKeyValue("name2", "B", "id", "0"));
1233}
1234
jbates@chromium.org88295f92012-03-01 12:04:59 +09001235// Test ASYNC_BEGIN/END events
1236TEST_F(TraceEventTestFixture, AsyncBeginEndPointerMangling) {
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +09001237 void* ptr = this;
1238
1239 TraceLog::GetInstance()->SetProcessID(100);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001240 BeginTrace();
jbates@chromium.org88295f92012-03-01 12:04:59 +09001241 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name1", ptr);
1242 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name2", ptr);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001243 EndTraceAndFlush();
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +09001244
1245 TraceLog::GetInstance()->SetProcessID(200);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001246 BeginTrace();
jbates@chromium.org88295f92012-03-01 12:04:59 +09001247 TRACE_EVENT_ASYNC_END0( "cat", "name1", ptr);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001248 EndTraceAndFlush();
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +09001249
jbates@chromium.org88295f92012-03-01 12:04:59 +09001250 DictionaryValue* async_begin = FindNamePhase("name1", "S");
1251 DictionaryValue* async_begin2 = FindNamePhase("name2", "S");
1252 DictionaryValue* async_end = FindNamePhase("name1", "F");
1253 EXPECT_TRUE(async_begin);
1254 EXPECT_TRUE(async_begin2);
1255 EXPECT_TRUE(async_end);
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +09001256
1257 Value* value = NULL;
jbates@chromium.org88295f92012-03-01 12:04:59 +09001258 std::string async_begin_id_str;
1259 std::string async_begin2_id_str;
1260 std::string async_end_id_str;
1261 ASSERT_TRUE(async_begin->Get("id", &value));
1262 ASSERT_TRUE(value->GetAsString(&async_begin_id_str));
1263 ASSERT_TRUE(async_begin2->Get("id", &value));
1264 ASSERT_TRUE(value->GetAsString(&async_begin2_id_str));
1265 ASSERT_TRUE(async_end->Get("id", &value));
1266 ASSERT_TRUE(value->GetAsString(&async_end_id_str));
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +09001267
jbates@chromium.org88295f92012-03-01 12:04:59 +09001268 EXPECT_STREQ(async_begin_id_str.c_str(), async_begin2_id_str.c_str());
1269 EXPECT_STRNE(async_begin_id_str.c_str(), async_end_id_str.c_str());
jbates@chromium.org8bb0ee62011-12-03 02:17:38 +09001270}
1271
jbates@chromium.org1f18e462011-09-07 02:56:24 +09001272// Test that static strings are not copied.
1273TEST_F(TraceEventTestFixture, StaticStringVsString) {
jbates@chromium.org1f18e462011-09-07 02:56:24 +09001274 TraceLog* tracer = TraceLog::GetInstance();
1275 // Make sure old events are flushed:
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001276 EndTraceAndFlush();
jbates@chromium.org1f18e462011-09-07 02:56:24 +09001277 EXPECT_EQ(0u, tracer->GetEventsSize());
wangxianzhu@chromium.orgf17afbd2013-10-21 12:51:13 +09001278 const unsigned char* category_group_enabled =
1279 TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED("cat");
jbates@chromium.org1f18e462011-09-07 02:56:24 +09001280
1281 {
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001282 BeginTrace();
jbates@chromium.org1f18e462011-09-07 02:56:24 +09001283 // Test that string arguments are copied.
wangxianzhu@chromium.orgf17afbd2013-10-21 12:51:13 +09001284 base::debug::TraceEventHandle handle1 =
1285 trace_event_internal::AddTraceEvent(
1286 TRACE_EVENT_PHASE_INSTANT, category_group_enabled, "name1", 0, 0,
1287 "arg1", std::string("argval"), "arg2", std::string("argval"));
jbates@chromium.org1f18e462011-09-07 02:56:24 +09001288 // Test that static TRACE_STR_COPY string arguments are copied.
wangxianzhu@chromium.orgf17afbd2013-10-21 12:51:13 +09001289 base::debug::TraceEventHandle handle2 =
1290 trace_event_internal::AddTraceEvent(
1291 TRACE_EVENT_PHASE_INSTANT, category_group_enabled, "name2", 0, 0,
1292 "arg1", TRACE_STR_COPY("argval"),
1293 "arg2", TRACE_STR_COPY("argval"));
jbates@chromium.org1f18e462011-09-07 02:56:24 +09001294 size_t num_events = tracer->GetEventsSize();
1295 EXPECT_GT(num_events, 1u);
wangxianzhu@chromium.orgf17afbd2013-10-21 12:51:13 +09001296 const TraceEvent* event1 = tracer->GetEventByHandle(handle1);
1297 const TraceEvent* event2 = tracer->GetEventByHandle(handle2);
wangxianzhu@chromium.org6aee1f72013-10-10 18:45:32 +09001298 ASSERT_TRUE(event1);
1299 ASSERT_TRUE(event2);
1300 EXPECT_STREQ("name1", event1->name());
1301 EXPECT_STREQ("name2", event2->name());
1302 EXPECT_TRUE(event1->parameter_copy_storage() != NULL);
1303 EXPECT_TRUE(event2->parameter_copy_storage() != NULL);
1304 EXPECT_GT(event1->parameter_copy_storage()->size(), 0u);
1305 EXPECT_GT(event2->parameter_copy_storage()->size(), 0u);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001306 EndTraceAndFlush();
jbates@chromium.org1f18e462011-09-07 02:56:24 +09001307 }
1308
1309 {
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001310 BeginTrace();
jbates@chromium.org1f18e462011-09-07 02:56:24 +09001311 // Test that static literal string arguments are not copied.
wangxianzhu@chromium.orgf17afbd2013-10-21 12:51:13 +09001312 base::debug::TraceEventHandle handle1 =
1313 trace_event_internal::AddTraceEvent(
1314 TRACE_EVENT_PHASE_INSTANT, category_group_enabled, "name1", 0, 0,
1315 "arg1", "argval", "arg2", "argval");
jbates@chromium.org1f18e462011-09-07 02:56:24 +09001316 // Test that static TRACE_STR_COPY NULL string arguments are not copied.
1317 const char* str1 = NULL;
1318 const char* str2 = NULL;
wangxianzhu@chromium.orgf17afbd2013-10-21 12:51:13 +09001319 base::debug::TraceEventHandle handle2 =
1320 trace_event_internal::AddTraceEvent(
1321 TRACE_EVENT_PHASE_INSTANT, category_group_enabled, "name2", 0, 0,
1322 "arg1", TRACE_STR_COPY(str1),
1323 "arg2", TRACE_STR_COPY(str2));
jbates@chromium.org1f18e462011-09-07 02:56:24 +09001324 size_t num_events = tracer->GetEventsSize();
1325 EXPECT_GT(num_events, 1u);
wangxianzhu@chromium.orgf17afbd2013-10-21 12:51:13 +09001326 const TraceEvent* event1 = tracer->GetEventByHandle(handle1);
1327 const TraceEvent* event2 = tracer->GetEventByHandle(handle2);
wangxianzhu@chromium.org6aee1f72013-10-10 18:45:32 +09001328 ASSERT_TRUE(event1);
1329 ASSERT_TRUE(event2);
1330 EXPECT_STREQ("name1", event1->name());
1331 EXPECT_STREQ("name2", event2->name());
1332 EXPECT_TRUE(event1->parameter_copy_storage() == NULL);
1333 EXPECT_TRUE(event2->parameter_copy_storage() == NULL);
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001334 EndTraceAndFlush();
jbates@chromium.org1f18e462011-09-07 02:56:24 +09001335 }
1336}
1337
scheib@chromium.org603f46e2011-05-10 11:23:58 +09001338// Test that data sent from other threads is gathered
1339TEST_F(TraceEventTestFixture, DataCapturedOnThread) {
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001340 BeginTrace();
scheib@chromium.org603f46e2011-05-10 11:23:58 +09001341
1342 Thread thread("1");
1343 WaitableEvent task_complete_event(false, false);
1344 thread.Start();
1345
1346 thread.message_loop()->PostTask(
jbates@chromium.org0b837e42011-10-06 01:58:20 +09001347 FROM_HERE, base::Bind(&TraceWithAllMacroVariants, &task_complete_event));
scheib@chromium.org603f46e2011-05-10 11:23:58 +09001348 task_complete_event.Wait();
jbates@chromium.orgb84db522011-10-04 02:51:25 +09001349 thread.Stop();
scheib@chromium.org603f46e2011-05-10 11:23:58 +09001350
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001351 EndTraceAndFlush();
jbates@chromium.org6a092d72011-10-25 01:34:08 +09001352 ValidateAllTraceMacrosCreatedData(trace_parsed_);
scheib@chromium.org603f46e2011-05-10 11:23:58 +09001353}
1354
scheib@chromium.org603f46e2011-05-10 11:23:58 +09001355// Test that data sent from multiple threads is gathered
1356TEST_F(TraceEventTestFixture, DataCapturedManyThreads) {
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001357 BeginTrace();
scheib@chromium.org603f46e2011-05-10 11:23:58 +09001358
1359 const int num_threads = 4;
1360 const int num_events = 4000;
1361 Thread* threads[num_threads];
1362 WaitableEvent* task_complete_events[num_threads];
1363 for (int i = 0; i < num_threads; i++) {
1364 threads[i] = new Thread(StringPrintf("Thread %d", i).c_str());
1365 task_complete_events[i] = new WaitableEvent(false, false);
1366 threads[i]->Start();
1367 threads[i]->message_loop()->PostTask(
jbates@chromium.org0b837e42011-10-06 01:58:20 +09001368 FROM_HERE, base::Bind(&TraceManyInstantEvents,
1369 i, num_events, task_complete_events[i]));
scheib@chromium.org603f46e2011-05-10 11:23:58 +09001370 }
1371
1372 for (int i = 0; i < num_threads; i++) {
1373 task_complete_events[i]->Wait();
1374 }
1375
wangxianzhu@chromium.orgd787d4f2013-09-07 05:18:05 +09001376 // Let half of the threads end before flush.
1377 for (int i = 0; i < num_threads / 2; i++) {
scheib@chromium.org603f46e2011-05-10 11:23:58 +09001378 threads[i]->Stop();
1379 delete threads[i];
1380 delete task_complete_events[i];
1381 }
1382
wangxianzhu@chromium.orgd787d4f2013-09-07 05:18:05 +09001383 WaitableEvent flush_complete_event(false, false);
1384 Thread flush_thread("flush");
1385 flush_thread.Start();
1386 flush_thread.message_loop()->PostTask(FROM_HERE,
1387 base::Bind(&TraceEventTestFixture::EndTraceAndFlushAsync,
1388 base::Unretained(this),
1389 &flush_complete_event));
1390 flush_complete_event.Wait();
jbates@chromium.org6a092d72011-10-25 01:34:08 +09001391 ValidateInstantEventPresentOnEveryThread(trace_parsed_,
nduca@chromium.org6d048772011-08-10 00:16:25 +09001392 num_threads, num_events);
wangxianzhu@chromium.orgd787d4f2013-09-07 05:18:05 +09001393
1394 // Let the other half of the threads end after flush.
1395 for (int i = num_threads / 2; i < num_threads; i++) {
1396 threads[i]->Stop();
1397 delete threads[i];
1398 delete task_complete_events[i];
1399 }
scheib@chromium.org603f46e2011-05-10 11:23:58 +09001400}
1401
nduca@chromium.org6d048772011-08-10 00:16:25 +09001402// Test that thread and process names show up in the trace
1403TEST_F(TraceEventTestFixture, ThreadNames) {
nduca@chromium.org6d048772011-08-10 00:16:25 +09001404 // Create threads before we enable tracing to make sure
1405 // that tracelog still captures them.
1406 const int num_threads = 4;
1407 const int num_events = 10;
1408 Thread* threads[num_threads];
1409 PlatformThreadId thread_ids[num_threads];
1410 for (int i = 0; i < num_threads; i++)
1411 threads[i] = new Thread(StringPrintf("Thread %d", i).c_str());
1412
1413 // Enable tracing.
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001414 BeginTrace();
nduca@chromium.org6d048772011-08-10 00:16:25 +09001415
1416 // Now run some trace code on these threads.
1417 WaitableEvent* task_complete_events[num_threads];
1418 for (int i = 0; i < num_threads; i++) {
1419 task_complete_events[i] = new WaitableEvent(false, false);
1420 threads[i]->Start();
1421 thread_ids[i] = threads[i]->thread_id();
1422 threads[i]->message_loop()->PostTask(
jbates@chromium.org0b837e42011-10-06 01:58:20 +09001423 FROM_HERE, base::Bind(&TraceManyInstantEvents,
1424 i, num_events, task_complete_events[i]));
nduca@chromium.org6d048772011-08-10 00:16:25 +09001425 }
1426 for (int i = 0; i < num_threads; i++) {
1427 task_complete_events[i]->Wait();
1428 }
1429
1430 // Shut things down.
nduca@chromium.org6d048772011-08-10 00:16:25 +09001431 for (int i = 0; i < num_threads; i++) {
1432 threads[i]->Stop();
1433 delete threads[i];
1434 delete task_complete_events[i];
1435 }
1436
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001437 EndTraceAndFlush();
jbates@chromium.orgb84db522011-10-04 02:51:25 +09001438
nduca@chromium.org6d048772011-08-10 00:16:25 +09001439 std::string tmp;
1440 int tmp_int;
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +09001441 const DictionaryValue* item;
nduca@chromium.org6d048772011-08-10 00:16:25 +09001442
1443 // Make sure we get thread name metadata.
1444 // Note, the test suite may have created a ton of threads.
1445 // So, we'll have thread names for threads we didn't create.
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +09001446 std::vector<const DictionaryValue*> items =
nduca@chromium.org6d048772011-08-10 00:16:25 +09001447 FindTraceEntries(trace_parsed_, "thread_name");
1448 for (int i = 0; i < static_cast<int>(items.size()); i++) {
1449 item = items[i];
joth@chromium.org088ae012011-11-11 01:26:23 +09001450 ASSERT_TRUE(item);
nduca@chromium.org6d048772011-08-10 00:16:25 +09001451 EXPECT_TRUE(item->GetInteger("tid", &tmp_int));
1452
1453 // See if this thread name is one of the threads we just created
1454 for (int j = 0; j < num_threads; j++) {
1455 if(static_cast<int>(thread_ids[j]) != tmp_int)
1456 continue;
1457
jbates@chromium.org62a16662012-02-04 08:18:06 +09001458 std::string expected_name = StringPrintf("Thread %d", j);
nduca@chromium.org6d048772011-08-10 00:16:25 +09001459 EXPECT_TRUE(item->GetString("ph", &tmp) && tmp == "M");
1460 EXPECT_TRUE(item->GetInteger("pid", &tmp_int) &&
1461 tmp_int == static_cast<int>(base::GetCurrentProcId()));
jbates@chromium.org62a16662012-02-04 08:18:06 +09001462 // If the thread name changes or the tid gets reused, the name will be
1463 // a comma-separated list of thread names, so look for a substring.
nduca@chromium.org6d048772011-08-10 00:16:25 +09001464 EXPECT_TRUE(item->GetString("args.name", &tmp) &&
jbates@chromium.org62a16662012-02-04 08:18:06 +09001465 tmp.find(expected_name) != std::string::npos);
nduca@chromium.org6d048772011-08-10 00:16:25 +09001466 }
1467 }
scheib@chromium.org603f46e2011-05-10 11:23:58 +09001468}
1469
joth@chromium.org088ae012011-11-11 01:26:23 +09001470TEST_F(TraceEventTestFixture, ThreadNameChanges) {
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001471 BeginTrace();
joth@chromium.org088ae012011-11-11 01:26:23 +09001472
1473 PlatformThread::SetName("");
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001474 TRACE_EVENT_INSTANT0("drink", "water", TRACE_EVENT_SCOPE_THREAD);
joth@chromium.org088ae012011-11-11 01:26:23 +09001475
1476 PlatformThread::SetName("cafe");
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001477 TRACE_EVENT_INSTANT0("drink", "coffee", TRACE_EVENT_SCOPE_THREAD);
joth@chromium.org088ae012011-11-11 01:26:23 +09001478
1479 PlatformThread::SetName("shop");
1480 // No event here, so won't appear in combined name.
1481
1482 PlatformThread::SetName("pub");
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001483 TRACE_EVENT_INSTANT0("drink", "beer", TRACE_EVENT_SCOPE_THREAD);
1484 TRACE_EVENT_INSTANT0("drink", "wine", TRACE_EVENT_SCOPE_THREAD);
joth@chromium.org088ae012011-11-11 01:26:23 +09001485
1486 PlatformThread::SetName(" bar");
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001487 TRACE_EVENT_INSTANT0("drink", "whisky", TRACE_EVENT_SCOPE_THREAD);
joth@chromium.org088ae012011-11-11 01:26:23 +09001488
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001489 EndTraceAndFlush();
joth@chromium.org088ae012011-11-11 01:26:23 +09001490
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +09001491 std::vector<const DictionaryValue*> items =
joth@chromium.org088ae012011-11-11 01:26:23 +09001492 FindTraceEntries(trace_parsed_, "thread_name");
1493 EXPECT_EQ(1u, items.size());
1494 ASSERT_GT(items.size(), 0u);
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +09001495 const DictionaryValue* item = items[0];
joth@chromium.org088ae012011-11-11 01:26:23 +09001496 ASSERT_TRUE(item);
1497 int tid;
1498 EXPECT_TRUE(item->GetInteger("tid", &tid));
1499 EXPECT_EQ(PlatformThread::CurrentId(), static_cast<PlatformThreadId>(tid));
1500
1501 std::string expected_name = "cafe,pub, bar";
1502 std::string tmp;
1503 EXPECT_TRUE(item->GetString("args.name", &tmp));
1504 EXPECT_EQ(expected_name, tmp);
1505}
nduca@chromium.org6d048772011-08-10 00:16:25 +09001506
dsinclair@chromium.org3f838632013-05-08 05:17:27 +09001507// Test that the disabled trace categories are included/excluded from the
1508// trace output correctly.
1509TEST_F(TraceEventTestFixture, DisabledCategories) {
dsinclair@chromium.org3f838632013-05-08 05:17:27 +09001510 BeginTrace();
1511 TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("cc"), "first",
1512 TRACE_EVENT_SCOPE_THREAD);
1513 TRACE_EVENT_INSTANT0("included", "first", TRACE_EVENT_SCOPE_THREAD);
1514 EndTraceAndFlush();
1515 {
1516 const DictionaryValue* item = NULL;
1517 ListValue& trace_parsed = trace_parsed_;
1518 EXPECT_NOT_FIND_("disabled-by-default-cc");
1519 EXPECT_FIND_("included");
1520 }
1521 Clear();
1522
1523 BeginSpecificTrace("disabled-by-default-cc");
1524 TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("cc"), "second",
1525 TRACE_EVENT_SCOPE_THREAD);
1526 TRACE_EVENT_INSTANT0("other_included", "second", TRACE_EVENT_SCOPE_THREAD);
1527 EndTraceAndFlush();
1528
1529 {
1530 const DictionaryValue* item = NULL;
1531 ListValue& trace_parsed = trace_parsed_;
1532 EXPECT_FIND_("disabled-by-default-cc");
1533 EXPECT_FIND_("other_included");
1534 }
1535}
1536
joth@chromium.org113de992011-07-21 21:28:59 +09001537TEST_F(TraceEventTestFixture, NormallyNoDeepCopy) {
1538 // Test that the TRACE_EVENT macros do not deep-copy their string. If they
1539 // do so it may indicate a performance regression, but more-over it would
1540 // make the DEEP_COPY overloads redundant.
joth@chromium.org113de992011-07-21 21:28:59 +09001541 std::string name_string("event name");
1542
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001543 BeginTrace();
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001544 TRACE_EVENT_INSTANT0("category", name_string.c_str(),
1545 TRACE_EVENT_SCOPE_THREAD);
joth@chromium.org113de992011-07-21 21:28:59 +09001546
1547 // Modify the string in place (a wholesale reassignment may leave the old
1548 // string intact on the heap).
1549 name_string[0] = '@';
1550
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001551 EndTraceAndFlush();
joth@chromium.org113de992011-07-21 21:28:59 +09001552
1553 EXPECT_FALSE(FindTraceEntry(trace_parsed_, "event name"));
1554 EXPECT_TRUE(FindTraceEntry(trace_parsed_, name_string.c_str()));
1555}
1556
1557TEST_F(TraceEventTestFixture, DeepCopy) {
joth@chromium.org113de992011-07-21 21:28:59 +09001558 static const char kOriginalName1[] = "name1";
1559 static const char kOriginalName2[] = "name2";
1560 static const char kOriginalName3[] = "name3";
1561 std::string name1(kOriginalName1);
1562 std::string name2(kOriginalName2);
1563 std::string name3(kOriginalName3);
1564 std::string arg1("arg1");
1565 std::string arg2("arg2");
1566 std::string val1("val1");
1567 std::string val2("val2");
1568
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001569 BeginTrace();
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001570 TRACE_EVENT_COPY_INSTANT0("category", name1.c_str(),
1571 TRACE_EVENT_SCOPE_THREAD);
joth@chromium.org113de992011-07-21 21:28:59 +09001572 TRACE_EVENT_COPY_BEGIN1("category", name2.c_str(),
1573 arg1.c_str(), 5);
1574 TRACE_EVENT_COPY_END2("category", name3.c_str(),
jbates@chromium.org1f18e462011-09-07 02:56:24 +09001575 arg1.c_str(), val1,
1576 arg2.c_str(), val2);
joth@chromium.org113de992011-07-21 21:28:59 +09001577
1578 // As per NormallyNoDeepCopy, modify the strings in place.
1579 name1[0] = name2[0] = name3[0] = arg1[0] = arg2[0] = val1[0] = val2[0] = '@';
1580
jbates@chromium.org6f1b35c2012-09-01 09:52:15 +09001581 EndTraceAndFlush();
joth@chromium.org113de992011-07-21 21:28:59 +09001582
1583 EXPECT_FALSE(FindTraceEntry(trace_parsed_, name1.c_str()));
1584 EXPECT_FALSE(FindTraceEntry(trace_parsed_, name2.c_str()));
1585 EXPECT_FALSE(FindTraceEntry(trace_parsed_, name3.c_str()));
1586
vabr@chromium.orga8ca4fd2012-08-03 17:43:37 +09001587 const DictionaryValue* entry1 = FindTraceEntry(trace_parsed_, kOriginalName1);
1588 const DictionaryValue* entry2 = FindTraceEntry(trace_parsed_, kOriginalName2);
1589 const DictionaryValue* entry3 = FindTraceEntry(trace_parsed_, kOriginalName3);
joth@chromium.org113de992011-07-21 21:28:59 +09001590 ASSERT_TRUE(entry1);
1591 ASSERT_TRUE(entry2);
1592 ASSERT_TRUE(entry3);
1593
1594 int i;
1595 EXPECT_FALSE(entry2->GetInteger("args.@rg1", &i));
1596 EXPECT_TRUE(entry2->GetInteger("args.arg1", &i));
1597 EXPECT_EQ(5, i);
1598
1599 std::string s;
1600 EXPECT_TRUE(entry3->GetString("args.arg1", &s));
1601 EXPECT_EQ("val1", s);
1602 EXPECT_TRUE(entry3->GetString("args.arg2", &s));
1603 EXPECT_EQ("val2", s);
1604}
1605
jbates@chromium.org6a092d72011-10-25 01:34:08 +09001606// Test that TraceResultBuffer outputs the correct result whether it is added
1607// in chunks or added all at once.
1608TEST_F(TraceEventTestFixture, TraceResultBuffer) {
jbates@chromium.org6a092d72011-10-25 01:34:08 +09001609 Clear();
1610
1611 trace_buffer_.Start();
1612 trace_buffer_.AddFragment("bla1");
1613 trace_buffer_.AddFragment("bla2");
1614 trace_buffer_.AddFragment("bla3,bla4");
1615 trace_buffer_.Finish();
1616 EXPECT_STREQ(json_output_.json_output.c_str(), "[bla1,bla2,bla3,bla4]");
1617
1618 Clear();
1619
1620 trace_buffer_.Start();
1621 trace_buffer_.AddFragment("bla1,bla2,bla3,bla4");
1622 trace_buffer_.Finish();
1623 EXPECT_STREQ(json_output_.json_output.c_str(), "[bla1,bla2,bla3,bla4]");
1624}
1625
dsinclair@chromium.org1cde1592013-01-15 01:53:06 +09001626// Test that trace_event parameters are not evaluated if the tracing
1627// system is disabled.
1628TEST_F(TraceEventTestFixture, TracingIsLazy) {
dsinclair@chromium.org1cde1592013-01-15 01:53:06 +09001629 BeginTrace();
1630
1631 int a = 0;
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001632 TRACE_EVENT_INSTANT1("category", "test", TRACE_EVENT_SCOPE_THREAD, "a", a++);
dsinclair@chromium.org1cde1592013-01-15 01:53:06 +09001633 EXPECT_EQ(1, a);
1634
1635 TraceLog::GetInstance()->SetDisabled();
1636
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001637 TRACE_EVENT_INSTANT1("category", "test", TRACE_EVENT_SCOPE_THREAD, "a", a++);
dsinclair@chromium.org1cde1592013-01-15 01:53:06 +09001638 EXPECT_EQ(1, a);
1639
1640 EndTraceAndFlush();
1641}
1642
caseq@google.comedcf6262013-01-16 20:41:57 +09001643TEST_F(TraceEventTestFixture, TraceEnableDisable) {
caseq@google.comedcf6262013-01-16 20:41:57 +09001644 TraceLog* trace_log = TraceLog::GetInstance();
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001645 CategoryFilter cf_inc_all("*");
1646 trace_log->SetEnabled(cf_inc_all, TraceLog::RECORD_UNTIL_FULL);
caseq@google.comedcf6262013-01-16 20:41:57 +09001647 EXPECT_TRUE(trace_log->IsEnabled());
1648 trace_log->SetDisabled();
1649 EXPECT_FALSE(trace_log->IsEnabled());
1650
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001651 trace_log->SetEnabled(cf_inc_all, TraceLog::RECORD_UNTIL_FULL);
caseq@google.comedcf6262013-01-16 20:41:57 +09001652 EXPECT_TRUE(trace_log->IsEnabled());
1653 const std::vector<std::string> empty;
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001654 trace_log->SetEnabled(CategoryFilter(""), TraceLog::RECORD_UNTIL_FULL);
caseq@google.comedcf6262013-01-16 20:41:57 +09001655 EXPECT_TRUE(trace_log->IsEnabled());
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001656 trace_log->SetDisabled();
caseq@google.comedcf6262013-01-16 20:41:57 +09001657 EXPECT_TRUE(trace_log->IsEnabled());
1658 trace_log->SetDisabled();
1659 EXPECT_FALSE(trace_log->IsEnabled());
1660}
1661
1662TEST_F(TraceEventTestFixture, TraceCategoriesAfterNestedEnable) {
caseq@google.comedcf6262013-01-16 20:41:57 +09001663 TraceLog* trace_log = TraceLog::GetInstance();
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001664 trace_log->SetEnabled(CategoryFilter("foo,bar"), TraceLog::RECORD_UNTIL_FULL);
1665 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("foo"));
1666 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("bar"));
junov@chromium.org5daaa152013-08-17 04:02:53 +09001667 EXPECT_FALSE(*trace_log->GetCategoryGroupEnabled("baz"));
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001668 trace_log->SetEnabled(CategoryFilter("foo2"), TraceLog::RECORD_UNTIL_FULL);
1669 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("foo2"));
junov@chromium.org5daaa152013-08-17 04:02:53 +09001670 EXPECT_FALSE(*trace_log->GetCategoryGroupEnabled("baz"));
dsinclair@chromium.org3f838632013-05-08 05:17:27 +09001671 // The "" becomes the default catergory set when applied.
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001672 trace_log->SetEnabled(CategoryFilter(""), TraceLog::RECORD_UNTIL_FULL);
1673 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("foo"));
1674 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("baz"));
dsinclair@chromium.org3f838632013-05-08 05:17:27 +09001675 EXPECT_STREQ("-*Debug,-*Test",
1676 trace_log->GetCurrentCategoryFilter().ToString().c_str());
caseq@google.comedcf6262013-01-16 20:41:57 +09001677 trace_log->SetDisabled();
1678 trace_log->SetDisabled();
1679 trace_log->SetDisabled();
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001680 EXPECT_FALSE(*trace_log->GetCategoryGroupEnabled("foo"));
1681 EXPECT_FALSE(*trace_log->GetCategoryGroupEnabled("baz"));
caseq@google.comedcf6262013-01-16 20:41:57 +09001682
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001683 trace_log->SetEnabled(CategoryFilter("-foo,-bar"),
1684 TraceLog::RECORD_UNTIL_FULL);
1685 EXPECT_FALSE(*trace_log->GetCategoryGroupEnabled("foo"));
1686 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("baz"));
1687 trace_log->SetEnabled(CategoryFilter("moo"), TraceLog::RECORD_UNTIL_FULL);
1688 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("baz"));
1689 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("moo"));
dsinclair@chromium.org3f838632013-05-08 05:17:27 +09001690 EXPECT_FALSE(*trace_log->GetCategoryGroupEnabled("foo"));
1691 EXPECT_STREQ("-foo,-bar",
1692 trace_log->GetCurrentCategoryFilter().ToString().c_str());
1693 trace_log->SetDisabled();
1694 trace_log->SetDisabled();
1695
1696 // Make sure disabled categories aren't cleared if we set in the second.
1697 trace_log->SetEnabled(CategoryFilter("disabled-by-default-cc,foo"),
1698 TraceLog::RECORD_UNTIL_FULL);
junov@chromium.org5daaa152013-08-17 04:02:53 +09001699 EXPECT_FALSE(*trace_log->GetCategoryGroupEnabled("bar"));
dsinclair@chromium.org3f838632013-05-08 05:17:27 +09001700 trace_log->SetEnabled(CategoryFilter("disabled-by-default-gpu"),
1701 TraceLog::RECORD_UNTIL_FULL);
1702 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("disabled-by-default-cc"));
1703 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("disabled-by-default-gpu"));
1704 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("bar"));
1705 EXPECT_STREQ("disabled-by-default-cc,disabled-by-default-gpu",
1706 trace_log->GetCurrentCategoryFilter().ToString().c_str());
caseq@google.comedcf6262013-01-16 20:41:57 +09001707 trace_log->SetDisabled();
1708 trace_log->SetDisabled();
1709}
1710
dsinclair@chromium.orga7fb8d62013-02-23 11:09:53 +09001711TEST_F(TraceEventTestFixture, TraceOptionsParsing) {
dcheng@chromium.org8164c2c2013-04-09 17:46:45 +09001712 EXPECT_EQ(TraceLog::RECORD_UNTIL_FULL,
1713 TraceLog::TraceOptionsFromString(std::string()));
dsinclair@chromium.orga7fb8d62013-02-23 11:09:53 +09001714
1715 EXPECT_EQ(TraceLog::RECORD_UNTIL_FULL,
1716 TraceLog::TraceOptionsFromString("record-until-full"));
dsinclair@chromium.org9e717e82013-03-16 08:28:44 +09001717 EXPECT_EQ(TraceLog::RECORD_CONTINUOUSLY,
1718 TraceLog::TraceOptionsFromString("record-continuously"));
dsinclair@chromium.org7f451932013-06-25 08:25:01 +09001719 EXPECT_EQ(TraceLog::RECORD_UNTIL_FULL | TraceLog::ENABLE_SAMPLING,
1720 TraceLog::TraceOptionsFromString("enable-sampling"));
1721 EXPECT_EQ(TraceLog::RECORD_CONTINUOUSLY | TraceLog::ENABLE_SAMPLING,
1722 TraceLog::TraceOptionsFromString(
1723 "record-continuously,enable-sampling"));
dsinclair@chromium.orga7fb8d62013-02-23 11:09:53 +09001724}
1725
scottmg@chromium.orgcdd292f2013-02-26 10:39:52 +09001726TEST_F(TraceEventTestFixture, TraceSampling) {
scottmg@chromium.orgcdd292f2013-02-26 10:39:52 +09001727 event_watch_notification_ = 0;
1728 TraceLog::GetInstance()->SetEnabled(
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001729 CategoryFilter("*"),
scottmg@chromium.orgcdd292f2013-02-26 10:39:52 +09001730 TraceLog::Options(TraceLog::RECORD_UNTIL_FULL |
1731 TraceLog::ENABLE_SAMPLING));
1732
1733 WaitableEvent* sampled = new WaitableEvent(false, false);
1734 TraceLog::GetInstance()->InstallWaitableEventForSamplingTesting(sampled);
1735
haraken@chromium.org26881c62013-07-04 17:54:07 +09001736 TRACE_EVENT_SET_SAMPLING_STATE_FOR_BUCKET(1, "cc", "Stuff");
scottmg@chromium.orgcdd292f2013-02-26 10:39:52 +09001737 sampled->Wait();
haraken@chromium.org26881c62013-07-04 17:54:07 +09001738 TRACE_EVENT_SET_SAMPLING_STATE_FOR_BUCKET(1, "cc", "Things");
scottmg@chromium.orgcdd292f2013-02-26 10:39:52 +09001739 sampled->Wait();
1740
1741 EndTraceAndFlush();
1742
1743 // Make sure we hit at least once.
1744 EXPECT_TRUE(FindNamePhase("Stuff", "P"));
1745 EXPECT_TRUE(FindNamePhase("Things", "P"));
1746}
haraken@chromium.org26881c62013-07-04 17:54:07 +09001747
1748TEST_F(TraceEventTestFixture, TraceSamplingScope) {
haraken@chromium.org26881c62013-07-04 17:54:07 +09001749 event_watch_notification_ = 0;
1750 TraceLog::GetInstance()->SetEnabled(
1751 CategoryFilter("*"),
1752 TraceLog::Options(TraceLog::RECORD_UNTIL_FULL |
1753 TraceLog::ENABLE_SAMPLING));
1754
1755 WaitableEvent* sampled = new WaitableEvent(false, false);
1756 TraceLog::GetInstance()->InstallWaitableEventForSamplingTesting(sampled);
1757
1758 TRACE_EVENT_SCOPED_SAMPLING_STATE("AAA", "name");
1759 sampled->Wait();
1760 {
1761 EXPECT_STREQ(TRACE_EVENT_GET_SAMPLING_STATE(), "AAA");
1762 TRACE_EVENT_SCOPED_SAMPLING_STATE("BBB", "name");
1763 sampled->Wait();
1764 EXPECT_STREQ(TRACE_EVENT_GET_SAMPLING_STATE(), "BBB");
1765 }
1766 sampled->Wait();
1767 {
1768 EXPECT_STREQ(TRACE_EVENT_GET_SAMPLING_STATE(), "AAA");
1769 TRACE_EVENT_SCOPED_SAMPLING_STATE("CCC", "name");
1770 sampled->Wait();
1771 EXPECT_STREQ(TRACE_EVENT_GET_SAMPLING_STATE(), "CCC");
1772 }
1773 sampled->Wait();
1774 {
1775 EXPECT_STREQ(TRACE_EVENT_GET_SAMPLING_STATE(), "AAA");
1776 TRACE_EVENT_SET_SAMPLING_STATE("DDD", "name");
1777 sampled->Wait();
1778 EXPECT_STREQ(TRACE_EVENT_GET_SAMPLING_STATE(), "DDD");
1779 }
1780 sampled->Wait();
1781 EXPECT_STREQ(TRACE_EVENT_GET_SAMPLING_STATE(), "DDD");
1782
1783 EndTraceAndFlush();
1784}
scottmg@chromium.orgcdd292f2013-02-26 10:39:52 +09001785
haraken@chromium.org1722fea2013-10-08 10:01:25 +09001786TEST_F(TraceEventTestFixture, TraceContinuousSampling) {
1787 event_watch_notification_ = 0;
1788 TraceLog::GetInstance()->SetEnabled(
1789 CategoryFilter("*"),
1790 TraceLog::Options(TraceLog::MONITOR_SAMPLING));
1791
1792 WaitableEvent* sampled = new WaitableEvent(false, false);
1793 TraceLog::GetInstance()->InstallWaitableEventForSamplingTesting(
1794 sampled);
1795
1796 TRACE_EVENT_SET_SAMPLING_STATE_FOR_BUCKET(1, "category", "AAA");
1797 sampled->Wait();
1798 TRACE_EVENT_SET_SAMPLING_STATE_FOR_BUCKET(1, "category", "BBB");
1799 sampled->Wait();
1800
1801 FlushMonitoring();
1802
1803 // Make sure we can get the profiled data.
1804 EXPECT_TRUE(FindNamePhase("AAA", "P"));
1805 EXPECT_TRUE(FindNamePhase("BBB", "P"));
1806
1807 Clear();
1808 sampled->Wait();
1809
1810 TRACE_EVENT_SET_SAMPLING_STATE_FOR_BUCKET(1, "category", "CCC");
1811 sampled->Wait();
1812 TRACE_EVENT_SET_SAMPLING_STATE_FOR_BUCKET(1, "category", "DDD");
1813 sampled->Wait();
1814
1815 FlushMonitoring();
1816
1817 // Make sure the profiled data is accumulated.
1818 EXPECT_TRUE(FindNamePhase("AAA", "P"));
1819 EXPECT_TRUE(FindNamePhase("BBB", "P"));
1820 EXPECT_TRUE(FindNamePhase("CCC", "P"));
1821 EXPECT_TRUE(FindNamePhase("DDD", "P"));
1822
1823 Clear();
1824
1825 TraceLog::GetInstance()->SetDisabled();
1826
1827 // Make sure disabling the continuous sampling thread clears
1828 // the profiled data.
1829 EXPECT_FALSE(FindNamePhase("AAA", "P"));
1830 EXPECT_FALSE(FindNamePhase("BBB", "P"));
1831 EXPECT_FALSE(FindNamePhase("CCC", "P"));
1832 EXPECT_FALSE(FindNamePhase("DDD", "P"));
1833
1834 Clear();
1835}
1836
tonyg@chromium.orgff79f832013-05-04 00:40:47 +09001837class MyData : public base::debug::ConvertableToTraceFormat {
1838 public:
1839 MyData() {}
tonyg@chromium.orgff79f832013-05-04 00:40:47 +09001840
1841 virtual void AppendAsTraceFormat(std::string* out) const OVERRIDE {
1842 out->append("{\"foo\":1}");
1843 }
1844
1845 private:
wangxianzhu@chromium.orgd18a8462013-10-09 13:25:02 +09001846 virtual ~MyData() {}
tonyg@chromium.orgff79f832013-05-04 00:40:47 +09001847 DISALLOW_COPY_AND_ASSIGN(MyData);
1848};
1849
1850TEST_F(TraceEventTestFixture, ConvertableTypes) {
tonyg@chromium.orgff79f832013-05-04 00:40:47 +09001851 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"),
1852 TraceLog::RECORD_UNTIL_FULL);
1853
wangxianzhu@chromium.orgd18a8462013-10-09 13:25:02 +09001854 scoped_refptr<ConvertableToTraceFormat> data(new MyData());
1855 scoped_refptr<ConvertableToTraceFormat> data1(new MyData());
1856 scoped_refptr<ConvertableToTraceFormat> data2(new MyData());
1857 TRACE_EVENT1("foo", "bar", "data", data);
tonyg@chromium.orgff79f832013-05-04 00:40:47 +09001858 TRACE_EVENT2("foo", "baz",
wangxianzhu@chromium.orgd18a8462013-10-09 13:25:02 +09001859 "data1", data1,
1860 "data2", data2);
tonyg@chromium.orgff79f832013-05-04 00:40:47 +09001861
dsinclair@chromium.orgca96ff42013-05-09 00:17:35 +09001862
wangxianzhu@chromium.orgd18a8462013-10-09 13:25:02 +09001863 scoped_refptr<ConvertableToTraceFormat> convertData1(new MyData());
1864 scoped_refptr<ConvertableToTraceFormat> convertData2(new MyData());
dsinclair@chromium.orgca96ff42013-05-09 00:17:35 +09001865 TRACE_EVENT2(
1866 "foo",
1867 "string_first",
1868 "str",
1869 "string value 1",
1870 "convert",
wangxianzhu@chromium.orgd18a8462013-10-09 13:25:02 +09001871 convertData1);
dsinclair@chromium.orgca96ff42013-05-09 00:17:35 +09001872 TRACE_EVENT2(
1873 "foo",
1874 "string_second",
1875 "convert",
wangxianzhu@chromium.orgd18a8462013-10-09 13:25:02 +09001876 convertData2,
dsinclair@chromium.orgca96ff42013-05-09 00:17:35 +09001877 "str",
1878 "string value 2");
tonyg@chromium.orgff79f832013-05-04 00:40:47 +09001879 EndTraceAndFlush();
1880
dsinclair@chromium.orgca96ff42013-05-09 00:17:35 +09001881 // One arg version.
wangxianzhu@chromium.orgf17afbd2013-10-21 12:51:13 +09001882 DictionaryValue* dict = FindNamePhase("bar", "X");
tonyg@chromium.orgff79f832013-05-04 00:40:47 +09001883 ASSERT_TRUE(dict);
1884
1885 const DictionaryValue* args_dict = NULL;
1886 dict->GetDictionary("args", &args_dict);
1887 ASSERT_TRUE(args_dict);
1888
1889 const Value* value = NULL;
1890 const DictionaryValue* convertable_dict = NULL;
1891 EXPECT_TRUE(args_dict->Get("data", &value));
1892 ASSERT_TRUE(value->GetAsDictionary(&convertable_dict));
1893
1894 int foo_val;
1895 EXPECT_TRUE(convertable_dict->GetInteger("foo", &foo_val));
1896 EXPECT_EQ(1, foo_val);
1897
dsinclair@chromium.orgca96ff42013-05-09 00:17:35 +09001898 // Two arg version.
wangxianzhu@chromium.orgf17afbd2013-10-21 12:51:13 +09001899 dict = FindNamePhase("baz", "X");
tonyg@chromium.orgff79f832013-05-04 00:40:47 +09001900 ASSERT_TRUE(dict);
dsinclair@chromium.orgca96ff42013-05-09 00:17:35 +09001901
tonyg@chromium.orgff79f832013-05-04 00:40:47 +09001902 args_dict = NULL;
1903 dict->GetDictionary("args", &args_dict);
1904 ASSERT_TRUE(args_dict);
1905
1906 value = NULL;
1907 convertable_dict = NULL;
1908 EXPECT_TRUE(args_dict->Get("data1", &value));
1909 ASSERT_TRUE(value->GetAsDictionary(&convertable_dict));
1910
1911 value = NULL;
1912 convertable_dict = NULL;
1913 EXPECT_TRUE(args_dict->Get("data2", &value));
1914 ASSERT_TRUE(value->GetAsDictionary(&convertable_dict));
tonyg@chromium.orgff79f832013-05-04 00:40:47 +09001915
dsinclair@chromium.orgca96ff42013-05-09 00:17:35 +09001916 // Convertable with other types.
wangxianzhu@chromium.orgf17afbd2013-10-21 12:51:13 +09001917 dict = FindNamePhase("string_first", "X");
dsinclair@chromium.orgca96ff42013-05-09 00:17:35 +09001918 ASSERT_TRUE(dict);
1919
1920 args_dict = NULL;
1921 dict->GetDictionary("args", &args_dict);
1922 ASSERT_TRUE(args_dict);
1923
1924 std::string str_value;
1925 EXPECT_TRUE(args_dict->GetString("str", &str_value));
1926 EXPECT_STREQ("string value 1", str_value.c_str());
1927
1928 value = NULL;
1929 convertable_dict = NULL;
1930 foo_val = 0;
1931 EXPECT_TRUE(args_dict->Get("convert", &value));
1932 ASSERT_TRUE(value->GetAsDictionary(&convertable_dict));
1933 EXPECT_TRUE(convertable_dict->GetInteger("foo", &foo_val));
1934 EXPECT_EQ(1, foo_val);
1935
wangxianzhu@chromium.orgf17afbd2013-10-21 12:51:13 +09001936 dict = FindNamePhase("string_second", "X");
dsinclair@chromium.orgca96ff42013-05-09 00:17:35 +09001937 ASSERT_TRUE(dict);
1938
1939 args_dict = NULL;
1940 dict->GetDictionary("args", &args_dict);
1941 ASSERT_TRUE(args_dict);
1942
1943 EXPECT_TRUE(args_dict->GetString("str", &str_value));
1944 EXPECT_STREQ("string value 2", str_value.c_str());
1945
1946 value = NULL;
1947 convertable_dict = NULL;
1948 foo_val = 0;
1949 EXPECT_TRUE(args_dict->Get("convert", &value));
1950 ASSERT_TRUE(value->GetAsDictionary(&convertable_dict));
1951 EXPECT_TRUE(convertable_dict->GetInteger("foo", &foo_val));
1952 EXPECT_EQ(1, foo_val);
1953}
tonyg@chromium.orgff79f832013-05-04 00:40:47 +09001954
caseq@google.com5f3846c2013-02-27 18:11:12 +09001955class TraceEventCallbackTest : public TraceEventTestFixture {
1956 public:
1957 virtual void SetUp() OVERRIDE {
1958 TraceEventTestFixture::SetUp();
caseq@google.com5f3846c2013-02-27 18:11:12 +09001959 ASSERT_EQ(NULL, s_instance);
1960 s_instance = this;
1961 }
1962 virtual void TearDown() OVERRIDE {
1963 while (TraceLog::GetInstance()->IsEnabled())
1964 TraceLog::GetInstance()->SetDisabled();
1965 ASSERT_TRUE(!!s_instance);
1966 s_instance = NULL;
1967 TraceEventTestFixture::TearDown();
1968 }
1969
1970 protected:
1971 std::vector<std::string> collected_events_;
1972
1973 static TraceEventCallbackTest* s_instance;
1974 static void Callback(char phase,
1975 const unsigned char* category_enabled,
1976 const char* name,
1977 unsigned long long id,
1978 int num_args,
1979 const char* const arg_names[],
1980 const unsigned char arg_types[],
1981 const unsigned long long arg_values[],
1982 unsigned char flags) {
1983 s_instance->collected_events_.push_back(name);
1984 }
1985};
1986
1987TraceEventCallbackTest* TraceEventCallbackTest::s_instance;
1988
1989TEST_F(TraceEventCallbackTest, TraceEventCallback) {
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09001990 TRACE_EVENT_INSTANT0("all", "before enable", TRACE_EVENT_SCOPE_THREAD);
1991 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"),
1992 TraceLog::RECORD_UNTIL_FULL);
1993 TRACE_EVENT_INSTANT0("all", "before callback set", TRACE_EVENT_SCOPE_THREAD);
caseq@google.com5f3846c2013-02-27 18:11:12 +09001994 TraceLog::GetInstance()->SetEventCallback(Callback);
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001995 TRACE_EVENT_INSTANT0("all", "event1", TRACE_EVENT_SCOPE_GLOBAL);
1996 TRACE_EVENT_INSTANT0("all", "event2", TRACE_EVENT_SCOPE_GLOBAL);
caseq@google.com5f3846c2013-02-27 18:11:12 +09001997 TraceLog::GetInstance()->SetEventCallback(NULL);
simonjam@chromium.orgfd92ef32013-03-26 16:42:42 +09001998 TRACE_EVENT_INSTANT0("all", "after callback removed",
1999 TRACE_EVENT_SCOPE_GLOBAL);
caseq@google.com4cba9892013-04-29 18:08:28 +09002000 ASSERT_EQ(2u, collected_events_.size());
caseq@google.com5f3846c2013-02-27 18:11:12 +09002001 EXPECT_EQ("event1", collected_events_[0]);
2002 EXPECT_EQ("event2", collected_events_[1]);
2003}
2004
caseq@google.com4cba9892013-04-29 18:08:28 +09002005TEST_F(TraceEventCallbackTest, TraceEventCallbackWhileFull) {
2006 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"),
2007 TraceLog::RECORD_UNTIL_FULL);
2008 do {
2009 TRACE_EVENT_INSTANT0("all", "badger badger", TRACE_EVENT_SCOPE_GLOBAL);
2010 } while ((notifications_received_ & TraceLog::TRACE_BUFFER_FULL) == 0);
2011 TraceLog::GetInstance()->SetEventCallback(Callback);
2012 TRACE_EVENT_INSTANT0("all", "a snake", TRACE_EVENT_SCOPE_GLOBAL);
2013 TraceLog::GetInstance()->SetEventCallback(NULL);
2014 ASSERT_EQ(1u, collected_events_.size());
2015 EXPECT_EQ("a snake", collected_events_[0]);
2016}
2017
wangxianzhu@chromium.org6aee1f72013-10-10 18:45:32 +09002018TEST_F(TraceEventTestFixture, TraceBufferRingBufferGetReturnChunk) {
2019 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"),
2020 TraceLog::RECORD_CONTINUOUSLY);
2021 TraceBuffer* buffer = TraceLog::GetInstance()->trace_buffer();
2022 size_t capacity = buffer->Capacity();
2023 size_t num_chunks = capacity / TraceBufferChunk::kTraceBufferChunkSize;
2024 uint32 last_seq = 0;
2025 size_t chunk_index;
2026 EXPECT_EQ(0u, buffer->Size());
2027
2028 scoped_ptr<TraceBufferChunk*[]> chunks(new TraceBufferChunk*[num_chunks]);
2029 for (size_t i = 0; i < num_chunks; ++i) {
2030 chunks[i] = buffer->GetChunk(&chunk_index).release();
2031 EXPECT_TRUE(chunks[i]);
2032 EXPECT_EQ(i, chunk_index);
2033 EXPECT_GT(chunks[i]->seq(), last_seq);
2034 EXPECT_EQ((i + 1) * TraceBufferChunk::kTraceBufferChunkSize,
2035 buffer->Size());
2036 last_seq = chunks[i]->seq();
2037 }
2038
2039 // Ring buffer is never full.
2040 EXPECT_FALSE(buffer->IsFull());
2041
2042 // Return all chunks in original order.
2043 for (size_t i = 0; i < num_chunks; ++i)
2044 buffer->ReturnChunk(i, scoped_ptr<TraceBufferChunk>(chunks[i]));
2045
2046 // Should recycle the chunks in the returned order.
2047 for (size_t i = 0; i < num_chunks; ++i) {
2048 chunks[i] = buffer->GetChunk(&chunk_index).release();
2049 EXPECT_TRUE(chunks[i]);
2050 EXPECT_EQ(i, chunk_index);
2051 EXPECT_GT(chunks[i]->seq(), last_seq);
2052 last_seq = chunks[i]->seq();
2053 }
2054
2055 // Return all chunks in reverse order.
2056 for (size_t i = 0; i < num_chunks; ++i) {
2057 buffer->ReturnChunk(
2058 num_chunks - i - 1,
2059 scoped_ptr<TraceBufferChunk>(chunks[num_chunks - i - 1]));
2060 }
2061
2062 // Should recycle the chunks in the returned order.
2063 for (size_t i = 0; i < num_chunks; ++i) {
2064 chunks[i] = buffer->GetChunk(&chunk_index).release();
2065 EXPECT_TRUE(chunks[i]);
2066 EXPECT_EQ(num_chunks - i - 1, chunk_index);
2067 EXPECT_GT(chunks[i]->seq(), last_seq);
2068 last_seq = chunks[i]->seq();
2069 }
2070
2071 for (size_t i = 0; i < num_chunks; ++i)
2072 buffer->ReturnChunk(i, scoped_ptr<TraceBufferChunk>(chunks[i]));
2073
2074 TraceLog::GetInstance()->SetDisabled();
2075}
2076
2077TEST_F(TraceEventTestFixture, TraceBufferRingBufferHalfIteration) {
2078 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"),
2079 TraceLog::RECORD_CONTINUOUSLY);
2080 TraceBuffer* buffer = TraceLog::GetInstance()->trace_buffer();
2081 size_t capacity = buffer->Capacity();
2082 size_t num_chunks = capacity / TraceBufferChunk::kTraceBufferChunkSize;
2083 size_t chunk_index;
2084 EXPECT_EQ(0u, buffer->Size());
2085 EXPECT_FALSE(buffer->NextChunk());
2086
2087 size_t half_chunks = num_chunks / 2;
2088 scoped_ptr<TraceBufferChunk*[]> chunks(new TraceBufferChunk*[half_chunks]);
2089
2090 for (size_t i = 0; i < half_chunks; ++i) {
2091 chunks[i] = buffer->GetChunk(&chunk_index).release();
2092 EXPECT_TRUE(chunks[i]);
2093 EXPECT_EQ(i, chunk_index);
2094 }
2095 for (size_t i = 0; i < half_chunks; ++i)
2096 buffer->ReturnChunk(i, scoped_ptr<TraceBufferChunk>(chunks[i]));
2097
2098 for (size_t i = 0; i < half_chunks; ++i)
2099 EXPECT_EQ(chunks[i], buffer->NextChunk());
2100 EXPECT_FALSE(buffer->NextChunk());
2101 TraceLog::GetInstance()->SetDisabled();
2102}
2103
2104TEST_F(TraceEventTestFixture, TraceBufferRingBufferFullIteration) {
2105 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"),
2106 TraceLog::RECORD_CONTINUOUSLY);
2107 TraceBuffer* buffer = TraceLog::GetInstance()->trace_buffer();
2108 size_t capacity = buffer->Capacity();
2109 size_t num_chunks = capacity / TraceBufferChunk::kTraceBufferChunkSize;
2110 size_t chunk_index;
2111 EXPECT_EQ(0u, buffer->Size());
2112 EXPECT_FALSE(buffer->NextChunk());
2113
2114 scoped_ptr<TraceBufferChunk*[]> chunks(new TraceBufferChunk*[num_chunks]);
2115
2116 for (size_t i = 0; i < num_chunks; ++i) {
2117 chunks[i] = buffer->GetChunk(&chunk_index).release();
2118 EXPECT_TRUE(chunks[i]);
2119 EXPECT_EQ(i, chunk_index);
2120 }
2121 for (size_t i = 0; i < num_chunks; ++i)
2122 buffer->ReturnChunk(i, scoped_ptr<TraceBufferChunk>(chunks[i]));
2123
2124 for (size_t i = 0; i < num_chunks; ++i)
2125 EXPECT_TRUE(chunks[i] == buffer->NextChunk());
2126 EXPECT_FALSE(buffer->NextChunk());
2127 TraceLog::GetInstance()->SetDisabled();
2128}
dsinclair@chromium.org9e717e82013-03-16 08:28:44 +09002129
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09002130// Test the category filter.
2131TEST_F(TraceEventTestFixture, CategoryFilter) {
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09002132 // Using the default filter.
2133 CategoryFilter default_cf = CategoryFilter(
2134 CategoryFilter::kDefaultCategoryFilterString);
2135 std::string category_filter_str = default_cf.ToString();
2136 EXPECT_STREQ("-*Debug,-*Test", category_filter_str.c_str());
2137 EXPECT_TRUE(default_cf.IsCategoryGroupEnabled("not-excluded-category"));
dsinclair@chromium.org3f838632013-05-08 05:17:27 +09002138 EXPECT_FALSE(
2139 default_cf.IsCategoryGroupEnabled("disabled-by-default-category"));
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09002140 EXPECT_FALSE(default_cf.IsCategoryGroupEnabled("Category1,CategoryDebug"));
2141 EXPECT_FALSE(default_cf.IsCategoryGroupEnabled("CategoryDebug,Category1"));
2142 EXPECT_FALSE(default_cf.IsCategoryGroupEnabled("CategoryTest,Category2"));
2143
2144 // Make sure that upon an empty string, we fall back to the default filter.
2145 default_cf = CategoryFilter("");
2146 category_filter_str = default_cf.ToString();
2147 EXPECT_STREQ("-*Debug,-*Test", category_filter_str.c_str());
2148 EXPECT_TRUE(default_cf.IsCategoryGroupEnabled("not-excluded-category"));
2149 EXPECT_FALSE(default_cf.IsCategoryGroupEnabled("Category1,CategoryDebug"));
2150 EXPECT_FALSE(default_cf.IsCategoryGroupEnabled("CategoryDebug,Category1"));
2151 EXPECT_FALSE(default_cf.IsCategoryGroupEnabled("CategoryTest,Category2"));
2152
2153 // Using an arbitrary non-empty filter.
2154 CategoryFilter cf("included,-excluded,inc_pattern*,-exc_pattern*");
2155 category_filter_str = cf.ToString();
2156 EXPECT_STREQ("included,inc_pattern*,-excluded,-exc_pattern*",
2157 category_filter_str.c_str());
2158 EXPECT_TRUE(cf.IsCategoryGroupEnabled("included"));
2159 EXPECT_TRUE(cf.IsCategoryGroupEnabled("inc_pattern_category"));
2160 EXPECT_FALSE(cf.IsCategoryGroupEnabled("exc_pattern_category"));
2161 EXPECT_FALSE(cf.IsCategoryGroupEnabled("excluded"));
junov@chromium.org5daaa152013-08-17 04:02:53 +09002162 EXPECT_FALSE(cf.IsCategoryGroupEnabled("not-excluded-nor-included"));
2163 EXPECT_FALSE(cf.IsCategoryGroupEnabled("Category1,CategoryDebug"));
2164 EXPECT_FALSE(cf.IsCategoryGroupEnabled("CategoryDebug,Category1"));
2165 EXPECT_FALSE(cf.IsCategoryGroupEnabled("CategoryTest,Category2"));
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09002166
2167 cf.Merge(default_cf);
2168 category_filter_str = cf.ToString();
dsinclair@chromium.org3f838632013-05-08 05:17:27 +09002169 EXPECT_STREQ("-excluded,-exc_pattern*,-*Debug,-*Test",
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09002170 category_filter_str.c_str());
2171 cf.Clear();
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09002172
2173 CategoryFilter reconstructed_cf(category_filter_str);
2174 category_filter_str = reconstructed_cf.ToString();
dsinclair@chromium.org3f838632013-05-08 05:17:27 +09002175 EXPECT_STREQ("-excluded,-exc_pattern*,-*Debug,-*Test",
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09002176 category_filter_str.c_str());
2177
2178 // One included category.
2179 CategoryFilter one_inc_cf("only_inc_cat");
2180 category_filter_str = one_inc_cf.ToString();
2181 EXPECT_STREQ("only_inc_cat", category_filter_str.c_str());
2182
2183 // One excluded category.
2184 CategoryFilter one_exc_cf("-only_exc_cat");
2185 category_filter_str = one_exc_cf.ToString();
2186 EXPECT_STREQ("-only_exc_cat", category_filter_str.c_str());
2187
dsinclair@chromium.org3f838632013-05-08 05:17:27 +09002188 // Enabling a disabled- category does not require all categories to be traced
2189 // to be included.
2190 CategoryFilter disabled_cat("disabled-by-default-cc,-excluded");
2191 EXPECT_STREQ("disabled-by-default-cc,-excluded",
2192 disabled_cat.ToString().c_str());
2193 EXPECT_TRUE(disabled_cat.IsCategoryGroupEnabled("disabled-by-default-cc"));
2194 EXPECT_TRUE(disabled_cat.IsCategoryGroupEnabled("some_other_group"));
2195 EXPECT_FALSE(disabled_cat.IsCategoryGroupEnabled("excluded"));
2196
2197 // Enabled a disabled- category and also including makes all categories to
2198 // be traced require including.
2199 CategoryFilter disabled_inc_cat("disabled-by-default-cc,included");
2200 EXPECT_STREQ("included,disabled-by-default-cc",
2201 disabled_inc_cat.ToString().c_str());
2202 EXPECT_TRUE(
2203 disabled_inc_cat.IsCategoryGroupEnabled("disabled-by-default-cc"));
2204 EXPECT_TRUE(disabled_inc_cat.IsCategoryGroupEnabled("included"));
junov@chromium.org5daaa152013-08-17 04:02:53 +09002205 EXPECT_FALSE(disabled_inc_cat.IsCategoryGroupEnabled("other_included"));
dsinclair@chromium.org3f838632013-05-08 05:17:27 +09002206
rubentopo@gmail.com56a2b642013-04-19 17:49:03 +09002207 // Test that IsEmptyOrContainsLeadingOrTrailingWhitespace actually catches
2208 // categories that are explicitly forbiden.
2209 // This method is called in a DCHECK to assert that we don't have these types
2210 // of strings as categories.
2211 EXPECT_TRUE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace(
2212 " bad_category "));
2213 EXPECT_TRUE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace(
2214 " bad_category"));
2215 EXPECT_TRUE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace(
2216 "bad_category "));
2217 EXPECT_TRUE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace(
2218 " bad_category"));
2219 EXPECT_TRUE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace(
2220 "bad_category "));
2221 EXPECT_TRUE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace(
2222 " bad_category "));
2223 EXPECT_TRUE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace(
2224 ""));
2225 EXPECT_FALSE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace(
2226 "good_category"));
2227}
2228
scheib@chromium.org603f46e2011-05-10 11:23:58 +09002229} // namespace debug
2230} // namespace base