1 /*
2 * Copyright (C) 2018 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17 #include "src/trace_processor/importers/proto/proto_trace_tokenizer.h"
18
19 #include "perfetto/base/logging.h"
20 #include "perfetto/ext/base/string_view.h"
21 #include "perfetto/protozero/scattered_heap_buffer.h"
22 #include "src/trace_processor/additional_modules.h"
23 #include "src/trace_processor/args_tracker.h"
24 #include "src/trace_processor/clock_tracker.h"
25 #include "src/trace_processor/default_modules.h"
26 #include "src/trace_processor/event_tracker.h"
27 #include "src/trace_processor/importers/ftrace/sched_event_tracker.h"
28 #include "src/trace_processor/importers/proto/proto_trace_parser.h"
29 #include "src/trace_processor/metadata_tracker.h"
30 #include "src/trace_processor/process_tracker.h"
31 #include "src/trace_processor/slice_tracker.h"
32 #include "src/trace_processor/stack_profile_tracker.h"
33 #include "src/trace_processor/storage/metadata.h"
34 #include "src/trace_processor/storage/trace_storage.h"
35 #include "src/trace_processor/trace_sorter.h"
36 #include "src/trace_processor/track_tracker.h"
37 #include "test/gtest_and_gmock.h"
38
39 #include "protos/perfetto/common/sys_stats_counters.pbzero.h"
40 #include "protos/perfetto/trace/android/packages_list.pbzero.h"
41 #include "protos/perfetto/trace/chrome/chrome_benchmark_metadata.pbzero.h"
42 #include "protos/perfetto/trace/chrome/chrome_trace_event.pbzero.h"
43 #include "protos/perfetto/trace/clock_snapshot.pbzero.h"
44 #include "protos/perfetto/trace/ftrace/ftrace.pbzero.h"
45 #include "protos/perfetto/trace/ftrace/ftrace_event.pbzero.h"
46 #include "protos/perfetto/trace/ftrace/ftrace_event_bundle.pbzero.h"
47 #include "protos/perfetto/trace/ftrace/generic.pbzero.h"
48 #include "protos/perfetto/trace/ftrace/power.pbzero.h"
49 #include "protos/perfetto/trace/ftrace/sched.pbzero.h"
50 #include "protos/perfetto/trace/ftrace/task.pbzero.h"
51 #include "protos/perfetto/trace/interned_data/interned_data.pbzero.h"
52 #include "protos/perfetto/trace/profiling/profile_packet.pbzero.h"
53 #include "protos/perfetto/trace/ps/process_tree.pbzero.h"
54 #include "protos/perfetto/trace/sys_stats/sys_stats.pbzero.h"
55 #include "protos/perfetto/trace/trace.pbzero.h"
56 #include "protos/perfetto/trace/trace_packet.pbzero.h"
57 #include "protos/perfetto/trace/track_event/debug_annotation.pbzero.h"
58 #include "protos/perfetto/trace/track_event/log_message.pbzero.h"
59 #include "protos/perfetto/trace/track_event/process_descriptor.pbzero.h"
60 #include "protos/perfetto/trace/track_event/source_location.pbzero.h"
61 #include "protos/perfetto/trace/track_event/task_execution.pbzero.h"
62 #include "protos/perfetto/trace/track_event/thread_descriptor.pbzero.h"
63 #include "protos/perfetto/trace/track_event/track_descriptor.pbzero.h"
64 #include "protos/perfetto/trace/track_event/track_event.pbzero.h"
65
66 namespace perfetto {
67 namespace trace_processor {
68 namespace {
69
70 using ::testing::_;
71 using ::testing::Args;
72 using ::testing::AtLeast;
73 using ::testing::ElementsAreArray;
74 using ::testing::Eq;
75 using ::testing::InSequence;
76 using ::testing::Invoke;
77 using ::testing::InvokeArgument;
78 using ::testing::NiceMock;
79 using ::testing::Pointwise;
80 using ::testing::Return;
81 using ::testing::ReturnRef;
82 using ::testing::UnorderedElementsAreArray;
83
84 namespace {
85 MATCHER_P(DoubleEq, exp, "Double matcher that satisfies -Wfloat-equal") {
86 // The IEEE standard says that any comparison operation involving
87 // a NAN must return false.
88 double d_exp = exp;
89 double d_arg = arg;
90 if (isnan(d_exp) || isnan(d_arg))
91 return false;
92 return fabs(d_arg - d_exp) < 1e-128;
93 }
94 } // namespace
95
96 class MockSchedEventTracker : public SchedEventTracker {
97 public:
MockSchedEventTracker(TraceProcessorContext * context)98 MockSchedEventTracker(TraceProcessorContext* context)
99 : SchedEventTracker(context) {}
100
101 MOCK_METHOD9(PushSchedSwitch,
102 void(uint32_t cpu,
103 int64_t timestamp,
104 uint32_t prev_pid,
105 base::StringView prev_comm,
106 int32_t prev_prio,
107 int64_t prev_state,
108 uint32_t next_pid,
109 base::StringView next_comm,
110 int32_t next_prio));
111 };
112
113 class MockEventTracker : public EventTracker {
114 public:
MockEventTracker(TraceProcessorContext * context)115 MockEventTracker(TraceProcessorContext* context) : EventTracker(context) {}
116 virtual ~MockEventTracker() = default;
117
118 MOCK_METHOD9(PushSchedSwitch,
119 void(uint32_t cpu,
120 int64_t timestamp,
121 uint32_t prev_pid,
122 base::StringView prev_comm,
123 int32_t prev_prio,
124 int64_t prev_state,
125 uint32_t next_pid,
126 base::StringView next_comm,
127 int32_t next_prio));
128
129 MOCK_METHOD3(PushCounter,
130 base::Optional<CounterId>(int64_t timestamp,
131 double value,
132 TrackId track_id));
133 };
134
135 class MockProcessTracker : public ProcessTracker {
136 public:
MockProcessTracker(TraceProcessorContext * context)137 MockProcessTracker(TraceProcessorContext* context)
138 : ProcessTracker(context) {}
139
140 MOCK_METHOD3(SetProcessMetadata,
141 UniquePid(uint32_t pid,
142 base::Optional<uint32_t> ppid,
143 base::StringView process_name));
144
145 MOCK_METHOD2(UpdateThreadName,
146 UniqueTid(uint32_t tid, StringId thread_name_id));
147 MOCK_METHOD2(SetThreadNameIfUnset,
148 void(UniqueTid utid, StringId thread_name_id));
149 MOCK_METHOD2(UpdateThread, UniqueTid(uint32_t tid, uint32_t tgid));
150
151 MOCK_METHOD1(GetOrCreateProcess, UniquePid(uint32_t pid));
152 MOCK_METHOD2(SetProcessNameIfUnset,
153 void(UniquePid upid, StringId process_name_id));
154 };
155
156 class MockBoundInserter : public ArgsTracker::BoundInserter {
157 public:
MockBoundInserter()158 MockBoundInserter()
159 : ArgsTracker::BoundInserter(&tracker_, nullptr, 0u), tracker_(nullptr) {
160 ON_CALL(*this, AddArg(_, _, _, _)).WillByDefault(ReturnRef(*this));
161 }
162
163 MOCK_METHOD4(
164 AddArg,
165 ArgsTracker::BoundInserter&(StringId flat_key,
166 StringId key,
167 Variadic v,
168 ArgsTracker::UpdatePolicy update_policy));
169
170 private:
171 ArgsTracker tracker_;
172 };
173
174 class MockSliceTracker : public SliceTracker {
175 public:
MockSliceTracker(TraceProcessorContext * context)176 MockSliceTracker(TraceProcessorContext* context) : SliceTracker(context) {}
177
178 MOCK_METHOD5(Begin,
179 base::Optional<uint32_t>(int64_t timestamp,
180 TrackId track_id,
181 StringId cat,
182 StringId name,
183 SetArgsCallback args_callback));
184 MOCK_METHOD5(End,
185 base::Optional<uint32_t>(int64_t timestamp,
186 TrackId track_id,
187 StringId cat,
188 StringId name,
189 SetArgsCallback args_callback));
190 MOCK_METHOD6(Scoped,
191 base::Optional<uint32_t>(int64_t timestamp,
192 TrackId track_id,
193 StringId cat,
194 StringId name,
195 int64_t duration,
196 SetArgsCallback args_callback));
197 };
198
199 class ProtoTraceParserTest : public ::testing::Test {
200 public:
ProtoTraceParserTest()201 ProtoTraceParserTest() {
202 storage_ = new TraceStorage();
203 context_.storage.reset(storage_);
204 context_.track_tracker.reset(new TrackTracker(&context_));
205 context_.global_args_tracker.reset(new GlobalArgsTracker(&context_));
206 context_.args_tracker.reset(new ArgsTracker(&context_));
207 context_.metadata_tracker.reset(new MetadataTracker(&context_));
208 event_ = new MockEventTracker(&context_);
209 context_.event_tracker.reset(event_);
210 sched_ = new MockSchedEventTracker(&context_);
211 context_.sched_tracker.reset(sched_);
212 process_ = new MockProcessTracker(&context_);
213 context_.process_tracker.reset(process_);
214 slice_ = new MockSliceTracker(&context_);
215 context_.slice_tracker.reset(slice_);
216 clock_ = new ClockTracker(&context_);
217 context_.clock_tracker.reset(clock_);
218 context_.sorter.reset(new TraceSorter(CreateParser(), 0 /*window size*/));
219
220 RegisterDefaultModules(&context_);
221 RegisterAdditionalModules(&context_);
222 }
223
ResetTraceBuffers()224 void ResetTraceBuffers() {
225 heap_buf_.reset(new protozero::ScatteredHeapBuffer());
226 stream_writer_.reset(new protozero::ScatteredStreamWriter(heap_buf_.get()));
227 heap_buf_->set_writer(stream_writer_.get());
228 trace_.Reset(stream_writer_.get());
229 }
230
SetUp()231 void SetUp() override { ResetTraceBuffers(); }
232
Tokenize()233 util::Status Tokenize() {
234 trace_.Finalize();
235 std::vector<uint8_t> trace_bytes = heap_buf_->StitchSlices();
236 std::unique_ptr<uint8_t[]> raw_trace(new uint8_t[trace_bytes.size()]);
237 memcpy(raw_trace.get(), trace_bytes.data(), trace_bytes.size());
238 context_.chunk_reader.reset(new ProtoTraceTokenizer(&context_));
239 auto status =
240 context_.chunk_reader->Parse(std::move(raw_trace), trace_bytes.size());
241
242 ResetTraceBuffers();
243 return status;
244 }
245
HasArg(ArgSetId set_id,StringId key_id,Variadic value)246 bool HasArg(ArgSetId set_id, StringId key_id, Variadic value) {
247 const auto& args = storage_->arg_table();
248 RowMap rm = args.FilterToRowMap({args.arg_set_id().eq(set_id)});
249 bool found = false;
250 for (auto it = rm.IterateRows(); it; it.Next()) {
251 if (args.key()[it.row()] == key_id) {
252 EXPECT_EQ(args.flat_key()[it.row()], key_id);
253 if (storage_->GetArgValue(it.row()) == value) {
254 found = true;
255 break;
256 }
257 }
258 }
259 return found;
260 }
261
262 protected:
CreateParser()263 std::unique_ptr<TraceParser> CreateParser() {
264 return std::unique_ptr<TraceParser>(new ProtoTraceParser(&context_));
265 }
266
267 std::unique_ptr<protozero::ScatteredHeapBuffer> heap_buf_;
268 std::unique_ptr<protozero::ScatteredStreamWriter> stream_writer_;
269 protos::pbzero::Trace trace_;
270 TraceProcessorContext context_;
271 MockEventTracker* event_;
272 MockSchedEventTracker* sched_;
273 MockProcessTracker* process_;
274 MockSliceTracker* slice_;
275 ClockTracker* clock_;
276 TraceStorage* storage_;
277 };
278
279 // TODO(eseckler): Refactor these into a new file for ftrace tests.
280
TEST_F(ProtoTraceParserTest,LoadSingleEvent)281 TEST_F(ProtoTraceParserTest, LoadSingleEvent) {
282 auto* bundle = trace_.add_packet()->set_ftrace_events();
283 bundle->set_cpu(10);
284
285 auto* event = bundle->add_event();
286 event->set_timestamp(1000);
287 event->set_pid(12);
288
289 static const char kProc1Name[] = "proc1";
290 static const char kProc2Name[] = "proc2";
291 auto* sched_switch = event->set_sched_switch();
292 sched_switch->set_prev_pid(10);
293 sched_switch->set_prev_comm(kProc2Name);
294 sched_switch->set_prev_prio(256);
295 sched_switch->set_prev_state(32);
296 sched_switch->set_next_comm(kProc1Name);
297 sched_switch->set_next_pid(100);
298 sched_switch->set_next_prio(1024);
299
300 EXPECT_CALL(*sched_,
301 PushSchedSwitch(10, 1000, 10, base::StringView(kProc2Name), 256,
302 32, 100, base::StringView(kProc1Name), 1024));
303 Tokenize();
304 }
305
TEST_F(ProtoTraceParserTest,LoadEventsIntoRaw)306 TEST_F(ProtoTraceParserTest, LoadEventsIntoRaw) {
307 auto* bundle = trace_.add_packet()->set_ftrace_events();
308 bundle->set_cpu(10);
309
310 // This event is unknown and will only appear in
311 // raw events table.
312 auto* event = bundle->add_event();
313 event->set_timestamp(1000);
314 event->set_pid(12);
315 auto* task = event->set_task_newtask();
316 task->set_pid(123);
317 static const char task_newtask[] = "task_newtask";
318 task->set_comm(task_newtask);
319 task->set_clone_flags(12);
320 task->set_oom_score_adj(15);
321
322 // This event has specific parsing logic, but will
323 // also appear in raw events table.
324 event = bundle->add_event();
325 event->set_timestamp(1001);
326 event->set_pid(12);
327 auto* print = event->set_print();
328 print->set_ip(20);
329 static const char buf_value[] = "This is a print event";
330 print->set_buf(buf_value);
331
332 EXPECT_CALL(*process_, GetOrCreateProcess(123));
333
334 Tokenize();
335
336 const auto& raw = context_.storage->raw_table();
337 ASSERT_EQ(raw.row_count(), 2u);
338 const auto& args = context_.storage->arg_table();
339 ASSERT_EQ(args.row_count(), 6u);
340 // Order is by row and then by StringIds.
341 ASSERT_EQ(args.key()[0], context_.storage->InternString("comm"));
342 ASSERT_EQ(args.key()[1], context_.storage->InternString("pid"));
343 ASSERT_EQ(args.key()[2], context_.storage->InternString("oom_score_adj"));
344 ASSERT_EQ(args.key()[3], context_.storage->InternString("clone_flags"));
345 ASSERT_EQ(args.key()[4], context_.storage->InternString("ip"));
346 ASSERT_EQ(args.key()[5], context_.storage->InternString("buf"));
347 ASSERT_STREQ(context_.storage->GetString(args.string_value()[0]).c_str(),
348 task_newtask);
349 ASSERT_EQ(args.int_value()[1], 123);
350 ASSERT_EQ(args.int_value()[2], 15);
351 ASSERT_EQ(args.int_value()[3], 12);
352 ASSERT_EQ(args.int_value()[4], 20);
353 ASSERT_STREQ(context_.storage->GetString(args.string_value()[5]).c_str(),
354 buf_value);
355
356 // TODO(taylori): Add test ftrace event with all field types
357 // and test here.
358 }
359
TEST_F(ProtoTraceParserTest,LoadGenericFtrace)360 TEST_F(ProtoTraceParserTest, LoadGenericFtrace) {
361 auto* packet = trace_.add_packet();
362 packet->set_timestamp(100);
363
364 auto* bundle = packet->set_ftrace_events();
365 bundle->set_cpu(4);
366
367 auto* ftrace = bundle->add_event();
368 ftrace->set_timestamp(100);
369 ftrace->set_pid(10);
370
371 auto* generic = ftrace->set_generic();
372 generic->set_event_name("Test");
373
374 auto* field = generic->add_field();
375 field->set_name("meta1");
376 field->set_str_value("value1");
377
378 field = generic->add_field();
379 field->set_name("meta2");
380 field->set_int_value(-2);
381
382 field = generic->add_field();
383 field->set_name("meta3");
384 field->set_uint_value(3);
385
386 Tokenize();
387
388 const auto& raw = storage_->raw_table();
389
390 ASSERT_EQ(raw.row_count(), 1u);
391 ASSERT_EQ(raw.ts()[raw.row_count() - 1], 100);
392 ASSERT_EQ(storage_->thread_table().tid()[raw.utid()[raw.row_count() - 1]],
393 10u);
394 ASSERT_EQ(raw.name().GetString(raw.row_count() - 1), "Test");
395
396 auto set_id = raw.arg_set_id()[raw.row_count() - 1];
397
398 const auto& args = storage_->arg_table();
399 RowMap rm = args.FilterToRowMap({args.arg_set_id().eq(set_id)});
400
401 auto row = rm.Get(0);
402
403 ASSERT_EQ(args.key().GetString(row), "meta1");
404 ASSERT_EQ(args.string_value().GetString(row++), "value1");
405
406 ASSERT_EQ(args.key().GetString(row), "meta2");
407 ASSERT_EQ(args.int_value()[row++], -2);
408
409 ASSERT_EQ(args.key().GetString(row), "meta3");
410 ASSERT_EQ(args.int_value()[row++], 3);
411 }
412
TEST_F(ProtoTraceParserTest,LoadMultipleEvents)413 TEST_F(ProtoTraceParserTest, LoadMultipleEvents) {
414 auto* bundle = trace_.add_packet()->set_ftrace_events();
415 bundle->set_cpu(10);
416
417 auto* event = bundle->add_event();
418 event->set_timestamp(1000);
419 event->set_pid(12);
420
421 static const char kProcName1[] = "proc1";
422 static const char kProcName2[] = "proc2";
423 auto* sched_switch = event->set_sched_switch();
424 sched_switch->set_prev_pid(10);
425 sched_switch->set_prev_comm(kProcName2);
426 sched_switch->set_prev_prio(256);
427 sched_switch->set_prev_state(32);
428 sched_switch->set_next_comm(kProcName1);
429 sched_switch->set_next_pid(100);
430 sched_switch->set_next_prio(1024);
431
432 event = bundle->add_event();
433 event->set_timestamp(1001);
434 event->set_pid(12);
435
436 sched_switch = event->set_sched_switch();
437 sched_switch->set_prev_pid(100);
438 sched_switch->set_prev_comm(kProcName1);
439 sched_switch->set_prev_prio(256);
440 sched_switch->set_prev_state(32);
441 sched_switch->set_next_comm(kProcName2);
442 sched_switch->set_next_pid(10);
443 sched_switch->set_next_prio(512);
444
445 EXPECT_CALL(*sched_,
446 PushSchedSwitch(10, 1000, 10, base::StringView(kProcName2), 256,
447 32, 100, base::StringView(kProcName1), 1024));
448
449 EXPECT_CALL(*sched_,
450 PushSchedSwitch(10, 1001, 100, base::StringView(kProcName1), 256,
451 32, 10, base::StringView(kProcName2), 512));
452
453 Tokenize();
454 }
455
TEST_F(ProtoTraceParserTest,LoadMultiplePackets)456 TEST_F(ProtoTraceParserTest, LoadMultiplePackets) {
457 auto* bundle = trace_.add_packet()->set_ftrace_events();
458 bundle->set_cpu(10);
459
460 auto* event = bundle->add_event();
461 event->set_timestamp(1000);
462 event->set_pid(12);
463
464 static const char kProcName1[] = "proc1";
465 static const char kProcName2[] = "proc2";
466 auto* sched_switch = event->set_sched_switch();
467 sched_switch->set_prev_pid(10);
468 sched_switch->set_prev_comm(kProcName2);
469 sched_switch->set_prev_prio(256);
470 sched_switch->set_prev_state(32);
471 sched_switch->set_next_comm(kProcName1);
472 sched_switch->set_next_pid(100);
473 sched_switch->set_next_prio(1024);
474
475 bundle = trace_.add_packet()->set_ftrace_events();
476 bundle->set_cpu(10);
477
478 event = bundle->add_event();
479 event->set_timestamp(1001);
480 event->set_pid(12);
481
482 sched_switch = event->set_sched_switch();
483 sched_switch->set_prev_pid(100);
484 sched_switch->set_prev_comm(kProcName1);
485 sched_switch->set_prev_prio(256);
486 sched_switch->set_prev_state(32);
487 sched_switch->set_next_comm(kProcName2);
488 sched_switch->set_next_pid(10);
489 sched_switch->set_next_prio(512);
490
491 EXPECT_CALL(*sched_,
492 PushSchedSwitch(10, 1000, 10, base::StringView(kProcName2), 256,
493 32, 100, base::StringView(kProcName1), 1024));
494
495 EXPECT_CALL(*sched_,
496 PushSchedSwitch(10, 1001, 100, base::StringView(kProcName1), 256,
497 32, 10, base::StringView(kProcName2), 512));
498 Tokenize();
499 }
500
TEST_F(ProtoTraceParserTest,RepeatedLoadSinglePacket)501 TEST_F(ProtoTraceParserTest, RepeatedLoadSinglePacket) {
502 auto* bundle = trace_.add_packet()->set_ftrace_events();
503 bundle->set_cpu(10);
504 auto* event = bundle->add_event();
505 event->set_timestamp(1000);
506 event->set_pid(12);
507 static const char kProcName1[] = "proc1";
508 static const char kProcName2[] = "proc2";
509 auto* sched_switch = event->set_sched_switch();
510 sched_switch->set_prev_pid(10);
511 sched_switch->set_prev_comm(kProcName2);
512 sched_switch->set_prev_prio(256);
513 sched_switch->set_prev_state(32);
514 sched_switch->set_next_comm(kProcName1);
515 sched_switch->set_next_pid(100);
516 sched_switch->set_next_prio(1024);
517 EXPECT_CALL(*sched_,
518 PushSchedSwitch(10, 1000, 10, base::StringView(kProcName2), 256,
519 32, 100, base::StringView(kProcName1), 1024));
520 Tokenize();
521
522 bundle = trace_.add_packet()->set_ftrace_events();
523 bundle->set_cpu(10);
524 event = bundle->add_event();
525 event->set_timestamp(1001);
526 event->set_pid(12);
527 sched_switch = event->set_sched_switch();
528 sched_switch->set_prev_pid(100);
529 sched_switch->set_prev_comm(kProcName1);
530 sched_switch->set_prev_prio(256);
531 sched_switch->set_prev_state(32);
532 sched_switch->set_next_comm(kProcName2);
533 sched_switch->set_next_pid(10);
534 sched_switch->set_next_prio(512);
535
536 EXPECT_CALL(*sched_,
537 PushSchedSwitch(10, 1001, 100, base::StringView(kProcName1), 256,
538 32, 10, base::StringView(kProcName2), 512));
539 Tokenize();
540 }
541
TEST_F(ProtoTraceParserTest,LoadCpuFreq)542 TEST_F(ProtoTraceParserTest, LoadCpuFreq) {
543 auto* bundle = trace_.add_packet()->set_ftrace_events();
544 bundle->set_cpu(12);
545 auto* event = bundle->add_event();
546 event->set_timestamp(1000);
547 event->set_pid(12);
548 auto* cpu_freq = event->set_cpu_frequency();
549 cpu_freq->set_cpu_id(10);
550 cpu_freq->set_state(2000);
551
552 EXPECT_CALL(*event_, PushCounter(1000, DoubleEq(2000), TrackId{0}));
553 Tokenize();
554
555 EXPECT_EQ(context_.storage->cpu_counter_track_table().cpu()[0], 10u);
556 }
557
TEST_F(ProtoTraceParserTest,LoadMemInfo)558 TEST_F(ProtoTraceParserTest, LoadMemInfo) {
559 auto* packet = trace_.add_packet();
560 uint64_t ts = 1000;
561 packet->set_timestamp(ts);
562 auto* bundle = packet->set_sys_stats();
563 auto* meminfo = bundle->add_meminfo();
564 meminfo->set_key(protos::pbzero::MEMINFO_MEM_TOTAL);
565 uint32_t value = 10;
566 meminfo->set_value(value);
567
568 EXPECT_CALL(*event_, PushCounter(static_cast<int64_t>(ts),
569 DoubleEq(value * 1024.0), TrackId{0u}));
570 Tokenize();
571
572 EXPECT_EQ(context_.storage->track_table().row_count(), 1u);
573 }
574
TEST_F(ProtoTraceParserTest,LoadVmStats)575 TEST_F(ProtoTraceParserTest, LoadVmStats) {
576 auto* packet = trace_.add_packet();
577 uint64_t ts = 1000;
578 packet->set_timestamp(ts);
579 auto* bundle = packet->set_sys_stats();
580 auto* meminfo = bundle->add_vmstat();
581 meminfo->set_key(protos::pbzero::VMSTAT_COMPACT_SUCCESS);
582 uint32_t value = 10;
583 meminfo->set_value(value);
584
585 EXPECT_CALL(*event_, PushCounter(static_cast<int64_t>(ts), DoubleEq(value),
586 TrackId{0u}));
587 Tokenize();
588
589 EXPECT_EQ(context_.storage->track_table().row_count(), 1u);
590 }
591
TEST_F(ProtoTraceParserTest,LoadProcessPacket)592 TEST_F(ProtoTraceParserTest, LoadProcessPacket) {
593 auto* tree = trace_.add_packet()->set_process_tree();
594 auto* process = tree->add_processes();
595 static const char kProcName1[] = "proc1";
596
597 process->add_cmdline(kProcName1);
598 process->set_pid(1);
599 process->set_ppid(3);
600
601 EXPECT_CALL(*process_,
602 SetProcessMetadata(1, Eq(3u), base::StringView(kProcName1)));
603 Tokenize();
604 }
605
TEST_F(ProtoTraceParserTest,LoadProcessPacket_FirstCmdline)606 TEST_F(ProtoTraceParserTest, LoadProcessPacket_FirstCmdline) {
607 auto* tree = trace_.add_packet()->set_process_tree();
608 auto* process = tree->add_processes();
609 static const char kProcName1[] = "proc1";
610 static const char kProcName2[] = "proc2";
611
612 process->add_cmdline(kProcName1);
613 process->add_cmdline(kProcName2);
614 process->set_pid(1);
615 process->set_ppid(3);
616
617 EXPECT_CALL(*process_,
618 SetProcessMetadata(1, Eq(3u), base::StringView(kProcName1)));
619 Tokenize();
620 }
621
TEST_F(ProtoTraceParserTest,LoadThreadPacket)622 TEST_F(ProtoTraceParserTest, LoadThreadPacket) {
623 auto* tree = trace_.add_packet()->set_process_tree();
624 auto* thread = tree->add_threads();
625 thread->set_tid(1);
626 thread->set_tgid(2);
627
628 EXPECT_CALL(*process_, UpdateThread(1, 2));
629 Tokenize();
630 }
631
TEST_F(ProtoTraceParserTest,ProcessNameFromProcessDescriptor)632 TEST_F(ProtoTraceParserTest, ProcessNameFromProcessDescriptor) {
633 context_.sorter.reset(new TraceSorter(
634 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
635 {
636 auto* packet = trace_.add_packet();
637 packet->set_trusted_packet_sequence_id(1);
638 packet->set_incremental_state_cleared(true);
639 auto* process_desc = packet->set_process_descriptor();
640 process_desc->set_pid(15);
641 process_desc->set_process_name("OldProcessName");
642 }
643 {
644 auto* packet = trace_.add_packet();
645 packet->set_trusted_packet_sequence_id(1);
646 packet->set_incremental_state_cleared(true);
647 auto* process_desc = packet->set_process_descriptor();
648 process_desc->set_pid(15);
649 process_desc->set_process_name("NewProcessName");
650 }
651 {
652 auto* packet = trace_.add_packet();
653 packet->set_trusted_packet_sequence_id(2);
654 packet->set_incremental_state_cleared(true);
655 auto* process_desc = packet->set_process_descriptor();
656 process_desc->set_pid(16);
657 process_desc->set_process_name("DifferentProcessName");
658 }
659
660 EXPECT_CALL(*process_, GetOrCreateProcess(15))
661 .WillRepeatedly(testing::Return(1u));
662 EXPECT_CALL(*process_, GetOrCreateProcess(16)).WillOnce(testing::Return(2u));
663
664 EXPECT_CALL(*process_, SetProcessNameIfUnset(
665 1u, storage_->InternString("OldProcessName")));
666 // Packet with same thread, but different name should update the name.
667 EXPECT_CALL(*process_, SetProcessNameIfUnset(
668 1u, storage_->InternString("NewProcessName")));
669 EXPECT_CALL(*process_,
670 SetProcessNameIfUnset(
671 2u, storage_->InternString("DifferentProcessName")));
672
673 Tokenize();
674 context_.sorter->ExtractEventsForced();
675 }
676
TEST_F(ProtoTraceParserTest,ThreadNameFromThreadDescriptor)677 TEST_F(ProtoTraceParserTest, ThreadNameFromThreadDescriptor) {
678 context_.sorter.reset(new TraceSorter(
679 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
680 {
681 auto* packet = trace_.add_packet();
682 packet->set_trusted_packet_sequence_id(1);
683 packet->set_incremental_state_cleared(true);
684 auto* thread_desc = packet->set_thread_descriptor();
685 thread_desc->set_pid(15);
686 thread_desc->set_tid(16);
687 thread_desc->set_reference_timestamp_us(1000);
688 thread_desc->set_reference_thread_time_us(2000);
689 thread_desc->set_thread_name("OldThreadName");
690 }
691 {
692 auto* packet = trace_.add_packet();
693 packet->set_trusted_packet_sequence_id(1);
694 packet->set_incremental_state_cleared(true);
695 auto* thread_desc = packet->set_thread_descriptor();
696 thread_desc->set_pid(15);
697 thread_desc->set_tid(16);
698 thread_desc->set_reference_timestamp_us(1000);
699 thread_desc->set_reference_thread_time_us(2000);
700 thread_desc->set_thread_name("NewThreadName");
701 }
702 {
703 auto* packet = trace_.add_packet();
704 packet->set_trusted_packet_sequence_id(2);
705 packet->set_incremental_state_cleared(true);
706 auto* thread_desc = packet->set_thread_descriptor();
707 thread_desc->set_pid(15);
708 thread_desc->set_tid(11);
709 thread_desc->set_reference_timestamp_us(1000);
710 thread_desc->set_reference_thread_time_us(2000);
711 thread_desc->set_thread_name("DifferentThreadName");
712 }
713
714 EXPECT_CALL(*process_, UpdateThread(16, 15))
715 .WillRepeatedly(testing::Return(1u));
716 EXPECT_CALL(*process_, UpdateThread(11, 15)).WillOnce(testing::Return(2u));
717
718 EXPECT_CALL(*process_, SetThreadNameIfUnset(
719 1u, storage_->InternString("OldThreadName")));
720 // Packet with same thread, but different name should update the name.
721 EXPECT_CALL(*process_, SetThreadNameIfUnset(
722 1u, storage_->InternString("NewThreadName")));
723 EXPECT_CALL(
724 *process_,
725 SetThreadNameIfUnset(2u, storage_->InternString("DifferentThreadName")));
726
727 Tokenize();
728 context_.sorter->ExtractEventsForced();
729 }
730
TEST_F(ProtoTraceParserTest,TrackEventWithoutInternedData)731 TEST_F(ProtoTraceParserTest, TrackEventWithoutInternedData) {
732 context_.sorter.reset(new TraceSorter(
733 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
734
735 {
736 auto* packet = trace_.add_packet();
737 packet->set_trusted_packet_sequence_id(1);
738 packet->set_incremental_state_cleared(true);
739 auto* thread_desc = packet->set_thread_descriptor();
740 thread_desc->set_pid(15);
741 thread_desc->set_tid(16);
742 thread_desc->set_reference_timestamp_us(1000);
743 thread_desc->set_reference_thread_time_us(2000);
744 }
745 {
746 auto* packet = trace_.add_packet();
747 packet->set_trusted_packet_sequence_id(1);
748 auto* event = packet->set_track_event();
749 event->set_timestamp_delta_us(10); // absolute: 1010.
750 event->set_thread_time_delta_us(5); // absolute: 2005.
751 event->add_category_iids(1);
752 auto* legacy_event = event->set_legacy_event();
753 legacy_event->set_name_iid(1);
754 legacy_event->set_phase('B');
755 }
756 {
757 auto* packet = trace_.add_packet();
758 packet->set_trusted_packet_sequence_id(1);
759 auto* event = packet->set_track_event();
760 event->set_timestamp_delta_us(10); // absolute: 1020.
761 event->set_thread_time_delta_us(5); // absolute: 2010.
762 event->add_category_iids(1);
763 auto* legacy_event = event->set_legacy_event();
764 legacy_event->set_name_iid(1);
765 legacy_event->set_phase('E');
766 }
767 {
768 auto* packet = trace_.add_packet();
769 packet->set_trusted_packet_sequence_id(1);
770 auto* event = packet->set_track_event();
771 event->set_timestamp_absolute_us(1005);
772 event->set_thread_time_absolute_us(2003);
773 event->add_category_iids(2);
774 event->add_category_iids(3);
775 auto* legacy_event = event->set_legacy_event();
776 legacy_event->set_name_iid(2);
777 legacy_event->set_phase('X');
778 legacy_event->set_duration_us(23); // absolute end: 1028.
779 legacy_event->set_thread_duration_us(12); // absolute end: 2015.
780 }
781
782 Tokenize();
783
784 EXPECT_CALL(*process_, UpdateThread(16, 15))
785 .WillRepeatedly(Return(1));
786
787 tables::ThreadTable::Row row(16);
788 row.upid = 1u;
789 storage_->mutable_thread_table()->Insert(row);
790
791 MockBoundInserter inserter;
792
793 StringId unknown_cat = storage_->InternString("unknown(1)");
794
795 constexpr TrackId track{0u};
796 InSequence in_sequence; // Below slices should be sorted by timestamp.
797 EXPECT_CALL(*slice_,
798 Scoped(1005000, track, kNullStringId, kNullStringId, 23000, _))
799 .WillOnce(DoAll(InvokeArgument<5>(&inserter), Return(0u)));
800 EXPECT_CALL(*slice_, Begin(1010000, track, unknown_cat, kNullStringId, _))
801 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(1u)));
802 EXPECT_CALL(*slice_, End(1020000, track, unknown_cat, kNullStringId, _))
803 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(1u)));
804
805 context_.sorter->ExtractEventsForced();
806
807 EXPECT_EQ(storage_->thread_slices().slice_count(), 2u);
808 EXPECT_EQ(storage_->thread_slices().slice_ids()[0], 0u);
809 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[0], 2003000);
810 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[0], 12000);
811 EXPECT_EQ(storage_->thread_slices().slice_ids()[1], 1u);
812 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[1], 2005000);
813 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[1], 5000);
814 }
815
TEST_F(ProtoTraceParserTest,TrackEventWithoutInternedDataWithTypes)816 TEST_F(ProtoTraceParserTest, TrackEventWithoutInternedDataWithTypes) {
817 context_.sorter.reset(new TraceSorter(
818 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
819
820 {
821 auto* packet = trace_.add_packet();
822 packet->set_trusted_packet_sequence_id(1);
823 packet->set_incremental_state_cleared(true);
824 auto* thread_desc = packet->set_thread_descriptor();
825 thread_desc->set_pid(15);
826 thread_desc->set_tid(16);
827 thread_desc->set_reference_timestamp_us(1000);
828 thread_desc->set_reference_thread_time_us(2000);
829 }
830 {
831 auto* packet = trace_.add_packet();
832 packet->set_trusted_packet_sequence_id(1);
833 auto* event = packet->set_track_event();
834 event->set_timestamp_delta_us(10); // absolute: 1010.
835 event->set_thread_time_delta_us(5); // absolute: 2005.
836 event->add_category_iids(1);
837 event->set_type(protos::pbzero::TrackEvent::TYPE_SLICE_BEGIN);
838 auto* legacy_event = event->set_legacy_event();
839 legacy_event->set_name_iid(1);
840 }
841 {
842 auto* packet = trace_.add_packet();
843 packet->set_trusted_packet_sequence_id(1);
844 auto* event = packet->set_track_event();
845 event->set_timestamp_delta_us(10); // absolute: 1020.
846 event->set_thread_time_delta_us(5); // absolute: 2010.
847 event->add_category_iids(1);
848 event->set_type(protos::pbzero::TrackEvent::TYPE_SLICE_END);
849 auto* legacy_event = event->set_legacy_event();
850 legacy_event->set_name_iid(1);
851 }
852 {
853 auto* packet = trace_.add_packet();
854 packet->set_trusted_packet_sequence_id(1);
855 auto* event = packet->set_track_event();
856 event->set_timestamp_absolute_us(1015);
857 event->set_thread_time_absolute_us(2007);
858 event->add_category_iids(2);
859 event->set_type(protos::pbzero::TrackEvent::TYPE_INSTANT);
860 auto* legacy_event = event->set_legacy_event();
861 legacy_event->set_name_iid(2);
862 }
863
864 Tokenize();
865
866 EXPECT_CALL(*process_, UpdateThread(16, 15))
867 .WillRepeatedly(Return(1));
868
869 tables::ThreadTable::Row row(16);
870 row.upid = 1u;
871 storage_->mutable_thread_table()->Insert(row);
872
873 MockBoundInserter inserter;
874
875 StringId unknown_cat1 = storage_->InternString("unknown(1)");
876 StringId unknown_cat2 = storage_->InternString("unknown(2)");
877
878 constexpr TrackId track{0u};
879 InSequence in_sequence; // Below slices should be sorted by timestamp.
880 EXPECT_CALL(*slice_, Begin(1010000, track, unknown_cat1, kNullStringId, _))
881 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(0u)));
882 EXPECT_CALL(*slice_,
883 Scoped(1015000, track, unknown_cat2, kNullStringId, 0, _))
884 .WillOnce(DoAll(InvokeArgument<5>(&inserter), Return(1u)));
885 EXPECT_CALL(*slice_, End(1020000, track, unknown_cat1, kNullStringId, _))
886 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(0u)));
887
888 context_.sorter->ExtractEventsForced();
889
890 EXPECT_EQ(storage_->thread_slices().slice_count(), 2u);
891 EXPECT_EQ(storage_->thread_slices().slice_ids()[0], 0u);
892 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[0], 2005000);
893 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[0], 5000);
894 EXPECT_EQ(storage_->thread_slices().slice_ids()[1], 1u);
895 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[1], 2007000);
896 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[1], 0);
897 }
898
TEST_F(ProtoTraceParserTest,TrackEventWithInternedData)899 TEST_F(ProtoTraceParserTest, TrackEventWithInternedData) {
900 context_.sorter.reset(new TraceSorter(
901 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
902
903 {
904 auto* packet = trace_.add_packet();
905 packet->set_trusted_packet_sequence_id(1);
906 packet->set_incremental_state_cleared(true);
907 auto* thread_desc = packet->set_thread_descriptor();
908 thread_desc->set_pid(15);
909 thread_desc->set_tid(16);
910 thread_desc->set_reference_timestamp_us(1000);
911 thread_desc->set_reference_thread_time_us(2000);
912 thread_desc->set_reference_thread_instruction_count(3000);
913 }
914 {
915 auto* packet = trace_.add_packet();
916 packet->set_trusted_packet_sequence_id(1);
917 auto* event = packet->set_track_event();
918 event->set_timestamp_delta_us(10); // absolute: 1010.
919 event->set_thread_time_delta_us(5); // absolute: 2005.
920 event->set_thread_instruction_count_delta(20); // absolute: 3020.
921 event->add_category_iids(1);
922 auto* legacy_event = event->set_legacy_event();
923 legacy_event->set_name_iid(1);
924 legacy_event->set_phase('B');
925
926 auto* interned_data = packet->set_interned_data();
927 auto cat1 = interned_data->add_event_categories();
928 cat1->set_iid(1);
929 cat1->set_name("cat1");
930 auto ev1 = interned_data->add_event_names();
931 ev1->set_iid(1);
932 ev1->set_name("ev1");
933 }
934 {
935 auto* packet = trace_.add_packet();
936 packet->set_trusted_packet_sequence_id(1);
937 auto* event = packet->set_track_event();
938 event->set_timestamp_absolute_us(1040);
939 event->set_thread_time_absolute_us(2030);
940 event->set_thread_instruction_count_absolute(3100);
941 event->add_category_iids(1);
942 auto* legacy_event = event->set_legacy_event();
943 legacy_event->set_name_iid(1);
944 legacy_event->set_phase('I');
945 }
946 {
947 auto* packet = trace_.add_packet();
948 packet->set_trusted_packet_sequence_id(1);
949 auto* event = packet->set_track_event();
950 event->set_timestamp_absolute_us(1050);
951 event->add_category_iids(1);
952 auto* legacy_event = event->set_legacy_event();
953 legacy_event->set_name_iid(1);
954 legacy_event->set_phase('i');
955 legacy_event->set_instant_event_scope(
956 protos::pbzero::TrackEvent::LegacyEvent::SCOPE_PROCESS);
957 }
958 {
959 auto* packet = trace_.add_packet();
960 packet->set_trusted_packet_sequence_id(1);
961 auto* event = packet->set_track_event();
962 event->set_timestamp_delta_us(10); // absolute: 1020.
963 event->set_thread_time_delta_us(5); // absolute: 2010.
964 event->set_thread_instruction_count_delta(20); // absolute: 3040.
965 event->add_category_iids(1);
966 auto* legacy_event = event->set_legacy_event();
967 legacy_event->set_name_iid(1);
968 legacy_event->set_phase('E');
969 }
970 {
971 auto* packet = trace_.add_packet();
972 packet->set_trusted_packet_sequence_id(1);
973 auto* event = packet->set_track_event();
974 event->set_timestamp_absolute_us(1005);
975 event->set_thread_time_absolute_us(2003);
976 event->set_thread_instruction_count_absolute(3010);
977 event->add_category_iids(2);
978 event->add_category_iids(3);
979 auto* legacy_event = event->set_legacy_event();
980 legacy_event->set_name_iid(4);
981 legacy_event->set_phase('X');
982 legacy_event->set_duration_us(23); // absolute end: 1028.
983 legacy_event->set_thread_duration_us(12); // absolute end: 2015.
984 legacy_event->set_thread_instruction_delta(50); // absolute end: 3060.
985 legacy_event->set_bind_id(9999);
986 legacy_event->set_bind_to_enclosing(true);
987 legacy_event->set_flow_direction(
988 protos::pbzero::TrackEvent::LegacyEvent::FLOW_INOUT);
989
990 auto* interned_data = packet->set_interned_data();
991 auto cat2 = interned_data->add_event_categories();
992 cat2->set_iid(2);
993 cat2->set_name("cat2");
994 auto cat3 = interned_data->add_event_categories();
995 cat3->set_iid(3);
996 cat3->set_name("cat3");
997 auto ev2 = interned_data->add_event_names();
998 ev2->set_iid(4);
999 ev2->set_name("ev2");
1000 }
1001
1002 Tokenize();
1003
1004 EXPECT_CALL(*process_, UpdateThread(16, 15))
1005 .WillRepeatedly(Return(1));
1006
1007 tables::ThreadTable::Row row(16);
1008 row.upid = 2u;
1009 storage_->mutable_thread_table()->Insert(row);
1010
1011 constexpr TrackId thread_1_track{0u};
1012 constexpr TrackId process_2_track{1u};
1013
1014 StringId cat_2_3 = storage_->InternString("cat2,cat3");
1015 StringId ev_2 = storage_->InternString("ev2");
1016 StringId cat_1 = storage_->InternString("cat1");
1017 StringId ev_1 = storage_->InternString("ev1");
1018
1019 InSequence in_sequence; // Below slices should be sorted by timestamp.
1020
1021 MockBoundInserter inserter;
1022 EXPECT_CALL(*slice_, Scoped(1005000, thread_1_track, cat_2_3, ev_2, 23000, _))
1023 .WillOnce(DoAll(InvokeArgument<5>(&inserter), Return(0u)));
1024 EXPECT_CALL(inserter, AddArg(_, _, Variadic::UnsignedInteger(9999u), _));
1025 EXPECT_CALL(inserter, AddArg(_, _, Variadic::Boolean(true), _));
1026 EXPECT_CALL(inserter, AddArg(_, _, _, _));
1027
1028 EXPECT_CALL(*slice_, Begin(1010000, thread_1_track, cat_1, ev_1, _))
1029 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(1u)));
1030
1031 EXPECT_CALL(*slice_, End(1020000, thread_1_track, cat_1, ev_1, _))
1032 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(1u)));
1033
1034 EXPECT_CALL(*slice_, Scoped(1040000, thread_1_track, cat_1, ev_1, 0, _))
1035 .WillOnce(DoAll(InvokeArgument<5>(&inserter), Return(2u)));
1036
1037 EXPECT_CALL(*slice_, Scoped(1050000, process_2_track, cat_1, ev_1, 0, _))
1038 .WillOnce(DoAll(InvokeArgument<5>(&inserter), Return(3u)));
1039 // Second slice should have a legacy_event.passthrough_utid arg.
1040 EXPECT_CALL(inserter, AddArg(_, _, Variadic::UnsignedInteger(1u), _));
1041
1042 context_.sorter->ExtractEventsForced();
1043
1044 EXPECT_EQ(storage_->thread_slices().slice_count(), 3u);
1045 EXPECT_EQ(storage_->thread_slices().slice_ids()[0], 0u);
1046 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[0], 2003000);
1047 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[0], 12000);
1048 EXPECT_EQ(storage_->thread_slices().thread_instruction_counts()[0], 3010);
1049 EXPECT_EQ(storage_->thread_slices().thread_instruction_deltas()[0], 50);
1050 EXPECT_EQ(storage_->thread_slices().slice_ids()[1], 1u);
1051 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[1], 2005000);
1052 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[1], 5000);
1053 EXPECT_EQ(storage_->thread_slices().thread_instruction_counts()[1], 3020);
1054 EXPECT_EQ(storage_->thread_slices().thread_instruction_deltas()[1], 20);
1055 EXPECT_EQ(storage_->thread_slices().slice_ids()[2], 2u);
1056 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[2], 2030000);
1057 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[2], 0);
1058 EXPECT_EQ(storage_->thread_slices().thread_instruction_counts()[2], 3100);
1059 EXPECT_EQ(storage_->thread_slices().thread_instruction_deltas()[2], 0);
1060 }
1061
TEST_F(ProtoTraceParserTest,TrackEventAsyncEvents)1062 TEST_F(ProtoTraceParserTest, TrackEventAsyncEvents) {
1063 context_.sorter.reset(new TraceSorter(
1064 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
1065
1066 {
1067 auto* packet = trace_.add_packet();
1068 packet->set_trusted_packet_sequence_id(1);
1069 packet->set_incremental_state_cleared(true);
1070 auto* thread_desc = packet->set_thread_descriptor();
1071 thread_desc->set_pid(15);
1072 thread_desc->set_tid(16);
1073 thread_desc->set_reference_timestamp_us(1000);
1074 thread_desc->set_reference_thread_time_us(2000);
1075 thread_desc->set_reference_thread_instruction_count(3000);
1076 }
1077 {
1078 auto* packet = trace_.add_packet();
1079 packet->set_trusted_packet_sequence_id(1);
1080 auto* event = packet->set_track_event();
1081 event->set_timestamp_delta_us(10); // absolute: 1010.
1082 event->set_thread_time_delta_us(5); // absolute: 2005.
1083 event->set_thread_instruction_count_delta(20); // absolute: 3020.
1084 event->add_category_iids(1);
1085 auto* legacy_event = event->set_legacy_event();
1086 legacy_event->set_name_iid(1);
1087 legacy_event->set_phase('b');
1088 legacy_event->set_global_id(10);
1089 legacy_event->set_use_async_tts(true);
1090
1091 auto* interned_data = packet->set_interned_data();
1092 auto cat1 = interned_data->add_event_categories();
1093 cat1->set_iid(1);
1094 cat1->set_name("cat1");
1095 auto ev1 = interned_data->add_event_names();
1096 ev1->set_iid(1);
1097 ev1->set_name("ev1");
1098 }
1099 {
1100 auto* packet = trace_.add_packet();
1101 packet->set_trusted_packet_sequence_id(1);
1102 auto* event = packet->set_track_event();
1103 event->set_timestamp_delta_us(10); // absolute: 1020.
1104 event->set_thread_time_delta_us(5); // absolute: 2010.
1105 event->set_thread_instruction_count_delta(20); // absolute: 3040.
1106 event->add_category_iids(1);
1107 auto* legacy_event = event->set_legacy_event();
1108 legacy_event->set_name_iid(1);
1109 legacy_event->set_phase('e');
1110 legacy_event->set_global_id(10);
1111 legacy_event->set_use_async_tts(true);
1112 }
1113 {
1114 auto* packet = trace_.add_packet();
1115 packet->set_trusted_packet_sequence_id(1);
1116 auto* event = packet->set_track_event();
1117 event->set_timestamp_absolute_us(1015);
1118 event->add_category_iids(1);
1119 auto* legacy_event = event->set_legacy_event();
1120 legacy_event->set_name_iid(2);
1121 legacy_event->set_phase('n');
1122 legacy_event->set_global_id(10);
1123
1124 auto* interned_data = packet->set_interned_data();
1125 auto ev2 = interned_data->add_event_names();
1126 ev2->set_iid(2);
1127 ev2->set_name("ev2");
1128 }
1129 {
1130 // Different category but same global_id -> separate track.
1131 auto* packet = trace_.add_packet();
1132 packet->set_trusted_packet_sequence_id(1);
1133 auto* event = packet->set_track_event();
1134 event->set_timestamp_absolute_us(1018);
1135 event->add_category_iids(2);
1136 auto* legacy_event = event->set_legacy_event();
1137 legacy_event->set_name_iid(2);
1138 legacy_event->set_phase('n');
1139 legacy_event->set_global_id(15);
1140
1141 auto* interned_data = packet->set_interned_data();
1142 auto cat2 = interned_data->add_event_categories();
1143 cat2->set_iid(2);
1144 cat2->set_name("cat2");
1145 }
1146 {
1147 auto* packet = trace_.add_packet();
1148 packet->set_trusted_packet_sequence_id(1);
1149 auto* event = packet->set_track_event();
1150 event->set_timestamp_absolute_us(1030);
1151 event->add_category_iids(2);
1152 auto* legacy_event = event->set_legacy_event();
1153 legacy_event->set_name_iid(2);
1154 legacy_event->set_phase('n');
1155 legacy_event->set_local_id(15);
1156 legacy_event->set_id_scope("scope1");
1157 }
1158
1159 Tokenize();
1160
1161 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillRepeatedly(Return(1));
1162
1163 tables::ThreadTable::Row row(16);
1164 row.upid = 1u;
1165 storage_->mutable_thread_table()->Insert(row);
1166
1167 StringId cat_1 = storage_->InternString("cat1");
1168 StringId ev_1 = storage_->InternString("ev1");
1169 StringId cat_2 = storage_->InternString("cat2");
1170 StringId ev_2 = storage_->InternString("ev2");
1171
1172 InSequence in_sequence; // Below slices should be sorted by timestamp.
1173
1174 EXPECT_CALL(*slice_, Begin(1010000, TrackId{1}, cat_1, ev_1, _))
1175 .WillOnce(Return(0u));
1176 EXPECT_CALL(*slice_, Scoped(1015000, TrackId{1}, cat_1, ev_2, 0, _));
1177 EXPECT_CALL(*slice_, Scoped(1018000, TrackId{2}, cat_2, ev_2, 0, _));
1178 EXPECT_CALL(*slice_, End(1020000, TrackId{1}, cat_1, ev_1, _))
1179 .WillOnce(Return(0u));
1180 EXPECT_CALL(*slice_, Scoped(1030000, TrackId{3}, cat_2, ev_2, 0, _));
1181
1182 context_.sorter->ExtractEventsForced();
1183
1184 // First track is for the thread; others are the async event tracks.
1185 EXPECT_EQ(storage_->track_table().row_count(), 4u);
1186 EXPECT_EQ(storage_->track_table().name()[1], ev_1);
1187 EXPECT_EQ(storage_->track_table().name()[2], ev_2);
1188 EXPECT_EQ(storage_->track_table().name()[3], ev_2);
1189
1190 EXPECT_EQ(storage_->process_track_table().row_count(), 3u);
1191 EXPECT_EQ(storage_->process_track_table().upid()[0], 1u);
1192 EXPECT_EQ(storage_->process_track_table().upid()[1], 1u);
1193 EXPECT_EQ(storage_->process_track_table().upid()[2], 1u);
1194
1195 EXPECT_EQ(storage_->virtual_track_slices().slice_count(), 1u);
1196 EXPECT_EQ(storage_->virtual_track_slices().slice_ids()[0], 0u);
1197 EXPECT_EQ(storage_->virtual_track_slices().thread_timestamp_ns()[0], 2005000);
1198 EXPECT_EQ(storage_->virtual_track_slices().thread_duration_ns()[0], 5000);
1199 EXPECT_EQ(storage_->virtual_track_slices().thread_instruction_counts()[0],
1200 3020);
1201 EXPECT_EQ(storage_->virtual_track_slices().thread_instruction_deltas()[0],
1202 20);
1203 }
1204
1205 // TODO(eseckler): Also test instant events on separate tracks.
TEST_F(ProtoTraceParserTest,TrackEventWithTrackDescriptors)1206 TEST_F(ProtoTraceParserTest, TrackEventWithTrackDescriptors) {
1207 context_.sorter.reset(new TraceSorter(
1208 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
1209
1210 // Sequence 1.
1211 {
1212 auto* packet = trace_.add_packet();
1213 packet->set_trusted_packet_sequence_id(1);
1214 packet->set_incremental_state_cleared(true);
1215 packet->set_timestamp(1000000);
1216 auto* track_desc = packet->set_track_descriptor();
1217 track_desc->set_uuid(1234);
1218 track_desc->set_name("Thread track 1");
1219 auto* thread_desc = track_desc->set_thread();
1220 thread_desc->set_pid(15);
1221 thread_desc->set_tid(16);
1222 }
1223 {
1224 auto* packet = trace_.add_packet();
1225 packet->set_trusted_packet_sequence_id(1);
1226 packet->set_timestamp(1000000);
1227 auto* track_desc = packet->set_track_descriptor();
1228 track_desc->set_uuid(5678);
1229 track_desc->set_name("Async track 1");
1230 }
1231 {
1232 // Async event started on "Async track 1".
1233 auto* packet = trace_.add_packet();
1234 packet->set_trusted_packet_sequence_id(1);
1235 packet->set_timestamp(1010000);
1236 auto* event = packet->set_track_event();
1237 event->set_track_uuid(5678);
1238 event->set_thread_time_absolute_us(2005);
1239 event->set_thread_instruction_count_absolute(3020);
1240 event->add_category_iids(1);
1241 event->set_name_iid(1);
1242 event->set_type(protos::pbzero::TrackEvent::TYPE_SLICE_BEGIN);
1243 auto* legacy_event = event->set_legacy_event();
1244 legacy_event->set_use_async_tts(true);
1245
1246 auto* interned_data = packet->set_interned_data();
1247 auto cat1 = interned_data->add_event_categories();
1248 cat1->set_iid(1);
1249 cat1->set_name("cat1");
1250 auto ev1 = interned_data->add_event_names();
1251 ev1->set_iid(1);
1252 ev1->set_name("ev1");
1253 }
1254 {
1255 // Instant event on "Thread track 1".
1256 auto* packet = trace_.add_packet();
1257 packet->set_trusted_packet_sequence_id(1);
1258 packet->set_timestamp(1015000);
1259 auto* event = packet->set_track_event();
1260 event->set_track_uuid(1234);
1261 event->set_thread_time_absolute_us(2007);
1262 event->add_category_iids(2);
1263 event->set_name_iid(2);
1264 event->set_type(protos::pbzero::TrackEvent::TYPE_INSTANT);
1265
1266 auto* interned_data = packet->set_interned_data();
1267 auto cat1 = interned_data->add_event_categories();
1268 cat1->set_iid(2);
1269 cat1->set_name("cat2");
1270 auto ev1 = interned_data->add_event_names();
1271 ev1->set_iid(2);
1272 ev1->set_name("ev2");
1273 }
1274
1275 // Sequence 2.
1276 {
1277 auto* packet = trace_.add_packet();
1278 packet->set_trusted_packet_sequence_id(2);
1279 packet->set_incremental_state_cleared(true);
1280 packet->set_timestamp(1000000);
1281 auto* track_desc = packet->set_track_descriptor();
1282 track_desc->set_uuid(4321);
1283 track_desc->set_name("Thread track 2");
1284 auto* thread_desc = track_desc->set_thread();
1285 thread_desc->set_pid(15);
1286 thread_desc->set_tid(17);
1287 }
1288 {
1289 // Async event completed on "Async track 1".
1290 auto* packet = trace_.add_packet();
1291 packet->set_trusted_packet_sequence_id(2);
1292 packet->set_timestamp(1020000);
1293 auto* event = packet->set_track_event();
1294 event->set_track_uuid(5678);
1295 event->set_thread_time_absolute_us(2010);
1296 event->set_thread_instruction_count_absolute(3040);
1297 event->set_type(protos::pbzero::TrackEvent::TYPE_SLICE_END);
1298 auto* legacy_event = event->set_legacy_event();
1299 legacy_event->set_use_async_tts(true);
1300 }
1301 {
1302 // Instant event on "Thread track 2".
1303 auto* packet = trace_.add_packet();
1304 packet->set_trusted_packet_sequence_id(2);
1305 packet->set_timestamp(1016000);
1306 auto* event = packet->set_track_event();
1307 event->set_track_uuid(4321);
1308 event->set_thread_time_absolute_us(2008);
1309 event->add_category_iids(1);
1310 event->set_name_iid(1);
1311 event->set_type(protos::pbzero::TrackEvent::TYPE_INSTANT);
1312
1313 auto* interned_data = packet->set_interned_data();
1314 auto cat1 = interned_data->add_event_categories();
1315 cat1->set_iid(1);
1316 cat1->set_name("cat3");
1317 auto ev1 = interned_data->add_event_names();
1318 ev1->set_iid(1);
1319 ev1->set_name("ev3");
1320 }
1321
1322 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillRepeatedly(Return(1));
1323 EXPECT_CALL(*process_, UpdateThread(17, 15)).WillRepeatedly(Return(2));
1324
1325 tables::ThreadTable::Row t1(16);
1326 t1.upid = 1u;
1327 storage_->mutable_thread_table()->Insert(t1);
1328
1329 tables::ThreadTable::Row t2(16);
1330 t2.upid = 2u;
1331 storage_->mutable_thread_table()->Insert(t2);
1332
1333 Tokenize();
1334
1335 StringId cat_1 = storage_->InternString("cat1");
1336 StringId ev_1 = storage_->InternString("ev1");
1337 StringId cat_2 = storage_->InternString("cat2");
1338 StringId ev_2 = storage_->InternString("ev2");
1339 StringId cat_3 = storage_->InternString("cat3");
1340 StringId ev_3 = storage_->InternString("ev3");
1341
1342 InSequence in_sequence; // Below slices should be sorted by timestamp.
1343
1344 EXPECT_CALL(*slice_, Begin(1010000, TrackId{1}, cat_1, ev_1, _))
1345 .WillOnce(Return(0u));
1346
1347 EXPECT_CALL(*slice_, Scoped(1015000, TrackId{0}, cat_2, ev_2, 0, _))
1348 .WillOnce(Return(1u));
1349
1350 EXPECT_CALL(*slice_, Scoped(1016000, TrackId{3}, cat_3, ev_3, 0, _))
1351 .WillOnce(Return(2u));
1352
1353 EXPECT_CALL(*slice_,
1354 End(1020000, TrackId{1}, kNullStringId, kNullStringId, _))
1355 .WillOnce(Return(0u));
1356
1357 context_.sorter->ExtractEventsForced();
1358
1359 // First track is "Thread track 1"; second is "Async track 1", third is global
1360 // default track (parent of async track), fourth is "Thread track 2".
1361 EXPECT_EQ(storage_->track_table().row_count(), 4u);
1362 EXPECT_EQ(storage_->track_table().name().GetString(0), "Thread track 1");
1363 EXPECT_EQ(storage_->track_table().name().GetString(1), "Async track 1");
1364 EXPECT_EQ(storage_->track_table().name().GetString(2), "Default Track");
1365 EXPECT_EQ(storage_->track_table().name().GetString(3), "Thread track 2");
1366 EXPECT_EQ(storage_->thread_track_table().row_count(), 2u);
1367 EXPECT_EQ(storage_->thread_track_table().utid()[0], 1u);
1368 EXPECT_EQ(storage_->thread_track_table().utid()[1], 2u);
1369
1370 EXPECT_EQ(storage_->virtual_track_slices().slice_count(), 1u);
1371 EXPECT_EQ(storage_->virtual_track_slices().slice_ids()[0], 0u);
1372 EXPECT_EQ(storage_->virtual_track_slices().thread_timestamp_ns()[0], 2005000);
1373 EXPECT_EQ(storage_->virtual_track_slices().thread_duration_ns()[0], 5000);
1374 EXPECT_EQ(storage_->virtual_track_slices().thread_instruction_counts()[0],
1375 3020);
1376 EXPECT_EQ(storage_->virtual_track_slices().thread_instruction_deltas()[0],
1377 20);
1378
1379 EXPECT_EQ(storage_->thread_slices().slice_count(), 2u);
1380 EXPECT_EQ(storage_->thread_slices().slice_ids()[0], 1u);
1381 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[0], 2007000);
1382 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[0], 0);
1383 EXPECT_EQ(storage_->thread_slices().thread_instruction_counts()[0], 0);
1384 EXPECT_EQ(storage_->thread_slices().thread_instruction_deltas()[0], 0);
1385 EXPECT_EQ(storage_->thread_slices().slice_ids()[1], 2u);
1386 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[1], 2008000);
1387 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[1], 0);
1388 EXPECT_EQ(storage_->thread_slices().thread_instruction_counts()[1], 0);
1389 EXPECT_EQ(storage_->thread_slices().thread_instruction_deltas()[1], 0);
1390 }
1391
TEST_F(ProtoTraceParserTest,TrackEventWithoutIncrementalStateReset)1392 TEST_F(ProtoTraceParserTest, TrackEventWithoutIncrementalStateReset) {
1393 context_.sorter.reset(new TraceSorter(
1394 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
1395
1396 {
1397 auto* packet = trace_.add_packet();
1398 packet->set_trusted_packet_sequence_id(1);
1399 auto* thread_desc = packet->set_thread_descriptor();
1400 thread_desc->set_pid(15);
1401 thread_desc->set_tid(16);
1402 thread_desc->set_reference_timestamp_us(1000);
1403 thread_desc->set_reference_thread_time_us(2000);
1404 }
1405 {
1406 // Event should be discarded because delta timestamps require valid
1407 // incremental state + thread descriptor.
1408 auto* packet = trace_.add_packet();
1409 packet->set_trusted_packet_sequence_id(1);
1410 auto* event = packet->set_track_event();
1411 event->set_timestamp_delta_us(10); // absolute: 1010.
1412 event->set_thread_time_delta_us(5); // absolute: 2005.
1413 event->add_category_iids(1);
1414 auto* legacy_event = event->set_legacy_event();
1415 legacy_event->set_name_iid(1);
1416 legacy_event->set_phase('B');
1417 }
1418 {
1419 // Event should be discarded because it specifies
1420 // SEQ_NEEDS_INCREMENTAL_STATE.
1421 auto* packet = trace_.add_packet();
1422 packet->set_timestamp(2000000);
1423 packet->set_trusted_packet_sequence_id(1);
1424 packet->set_sequence_flags(
1425 protos::pbzero::TracePacket::SEQ_NEEDS_INCREMENTAL_STATE);
1426 auto* event = packet->set_track_event();
1427 event->add_categories("cat");
1428 event->set_name("ev1");
1429 event->set_type(protos::pbzero::TrackEvent::TYPE_INSTANT);
1430 }
1431 {
1432 // Event should be accepted because it does not specify
1433 // SEQ_NEEDS_INCREMENTAL_STATE and uses absolute timestamps.
1434 auto* packet = trace_.add_packet();
1435 packet->set_timestamp(2100000);
1436 packet->set_trusted_packet_sequence_id(1);
1437 auto* event = packet->set_track_event();
1438 event->add_categories("cat1");
1439 event->set_name("ev2");
1440 event->set_type(protos::pbzero::TrackEvent::TYPE_INSTANT);
1441 }
1442
1443 Tokenize();
1444
1445 StringId cat1 = storage_->InternString("cat1");
1446 StringId ev2 = storage_->InternString("ev2");
1447
1448 EXPECT_CALL(*slice_, Scoped(2100000, TrackId{0}, cat1, ev2, 0, _))
1449 .WillOnce(Return(0u));
1450 context_.sorter->ExtractEventsForced();
1451 }
1452
TEST_F(ProtoTraceParserTest,TrackEventWithoutThreadDescriptor)1453 TEST_F(ProtoTraceParserTest, TrackEventWithoutThreadDescriptor) {
1454 context_.sorter.reset(new TraceSorter(
1455 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
1456
1457 {
1458 // Event should be discarded because it specifies delta timestamps and no
1459 // thread descriptor was seen yet.
1460 auto* packet = trace_.add_packet();
1461 packet->set_trusted_packet_sequence_id(1);
1462 packet->set_incremental_state_cleared(true);
1463 auto* event = packet->set_track_event();
1464 event->set_timestamp_delta_us(10);
1465 event->set_thread_time_delta_us(5);
1466 event->add_category_iids(1);
1467 auto* legacy_event = event->set_legacy_event();
1468 legacy_event->set_name_iid(1);
1469 legacy_event->set_phase('B');
1470 }
1471 {
1472 // Events that specify SEQ_NEEDS_INCREMENTAL_STATE should be accepted even
1473 // if there's no valid thread descriptor.
1474 auto* packet = trace_.add_packet();
1475 packet->set_timestamp(2000000);
1476 packet->set_trusted_packet_sequence_id(1);
1477 packet->set_sequence_flags(
1478 protos::pbzero::TracePacket::SEQ_NEEDS_INCREMENTAL_STATE);
1479 auto* event = packet->set_track_event();
1480 event->add_categories("cat1");
1481 event->set_name("ev1");
1482 event->set_type(protos::pbzero::TrackEvent::TYPE_INSTANT);
1483 }
1484
1485 Tokenize();
1486
1487 StringId cat1 = storage_->InternString("cat1");
1488 StringId ev1 = storage_->InternString("ev1");
1489
1490 EXPECT_CALL(*slice_, Scoped(2000000, TrackId{0}, cat1, ev1, 0, _))
1491 .WillOnce(Return(0u));
1492 context_.sorter->ExtractEventsForced();
1493 }
1494
TEST_F(ProtoTraceParserTest,TrackEventWithDataLoss)1495 TEST_F(ProtoTraceParserTest, TrackEventWithDataLoss) {
1496 context_.sorter.reset(new TraceSorter(
1497 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
1498
1499 {
1500 auto* packet = trace_.add_packet();
1501 packet->set_trusted_packet_sequence_id(1);
1502 packet->set_incremental_state_cleared(true);
1503 auto* thread_desc = packet->set_thread_descriptor();
1504 thread_desc->set_pid(15);
1505 thread_desc->set_tid(16);
1506 thread_desc->set_reference_timestamp_us(1000);
1507 thread_desc->set_reference_thread_time_us(2000);
1508 }
1509 {
1510 auto* packet = trace_.add_packet();
1511 packet->set_trusted_packet_sequence_id(1);
1512 auto* event = packet->set_track_event();
1513 event->set_timestamp_delta_us(10); // absolute: 1010.
1514 event->set_thread_time_delta_us(5); // absolute: 2005.
1515 event->add_category_iids(1);
1516 auto* legacy_event = event->set_legacy_event();
1517 legacy_event->set_name_iid(1);
1518 legacy_event->set_phase('B');
1519 }
1520 {
1521 // Event should be dropped because data loss occurred before.
1522 auto* packet = trace_.add_packet();
1523 packet->set_trusted_packet_sequence_id(1);
1524 packet->set_previous_packet_dropped(true); // Data loss occurred.
1525 auto* event = packet->set_track_event();
1526 event->set_timestamp_delta_us(10);
1527 event->set_thread_time_delta_us(5);
1528 event->add_category_iids(1);
1529 auto* legacy_event = event->set_legacy_event();
1530 legacy_event->set_name_iid(1);
1531 legacy_event->set_phase('E');
1532 }
1533 {
1534 // Event should be dropped because incremental state is invalid.
1535 auto* packet = trace_.add_packet();
1536 packet->set_trusted_packet_sequence_id(1);
1537 auto* event = packet->set_track_event();
1538 event->set_timestamp_delta_us(10);
1539 event->set_thread_time_delta_us(5);
1540 event->add_category_iids(1);
1541 auto* legacy_event = event->set_legacy_event();
1542 legacy_event->set_name_iid(1);
1543 legacy_event->set_phase('E');
1544 }
1545 {
1546 // Event should be dropped because no new thread descriptor was seen yet.
1547 auto* packet = trace_.add_packet();
1548 packet->set_trusted_packet_sequence_id(1);
1549 packet->set_incremental_state_cleared(true);
1550 auto* event = packet->set_track_event();
1551 event->set_timestamp_delta_us(10);
1552 event->set_thread_time_delta_us(5);
1553 event->add_category_iids(1);
1554 auto* legacy_event = event->set_legacy_event();
1555 legacy_event->set_name_iid(1);
1556 legacy_event->set_phase('E');
1557 }
1558 {
1559 auto* packet = trace_.add_packet();
1560 packet->set_trusted_packet_sequence_id(1);
1561 auto* thread_desc = packet->set_thread_descriptor();
1562 thread_desc->set_pid(15);
1563 thread_desc->set_tid(16);
1564 thread_desc->set_reference_timestamp_us(2000);
1565 thread_desc->set_reference_thread_time_us(3000);
1566 }
1567 {
1568 auto* packet = trace_.add_packet();
1569 packet->set_trusted_packet_sequence_id(1);
1570 auto* event = packet->set_track_event();
1571 event->set_timestamp_delta_us(10); // absolute: 2010.
1572 event->set_thread_time_delta_us(5); // absolute: 3005.
1573 event->add_category_iids(1);
1574 auto* legacy_event = event->set_legacy_event();
1575 legacy_event->set_name_iid(1);
1576 legacy_event->set_phase('E');
1577 }
1578
1579 Tokenize();
1580
1581 EXPECT_CALL(*process_, UpdateThread(16, 15))
1582 .WillRepeatedly(Return(1));
1583
1584 tables::ThreadTable::Row row(16);
1585 row.upid = 1u;
1586 storage_->mutable_thread_table()->Insert(row);
1587
1588 StringId unknown_cat = storage_->InternString("unknown(1)");
1589 constexpr TrackId track{0u};
1590 InSequence in_sequence; // Below slices should be sorted by timestamp.
1591 EXPECT_CALL(*slice_, Begin(1010000, track, unknown_cat, kNullStringId, _));
1592 EXPECT_CALL(*slice_, End(2010000, track, unknown_cat, kNullStringId, _));
1593
1594 context_.sorter->ExtractEventsForced();
1595 }
1596
TEST_F(ProtoTraceParserTest,TrackEventMultipleSequences)1597 TEST_F(ProtoTraceParserTest, TrackEventMultipleSequences) {
1598 context_.sorter.reset(new TraceSorter(
1599 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
1600
1601 {
1602 auto* packet = trace_.add_packet();
1603 packet->set_trusted_packet_sequence_id(1);
1604 packet->set_incremental_state_cleared(true);
1605 auto* thread_desc = packet->set_thread_descriptor();
1606 thread_desc->set_pid(15);
1607 thread_desc->set_tid(16);
1608 thread_desc->set_reference_timestamp_us(1000);
1609 thread_desc->set_reference_thread_time_us(2000);
1610 }
1611 {
1612 auto* packet = trace_.add_packet();
1613 packet->set_trusted_packet_sequence_id(1);
1614 auto* event = packet->set_track_event();
1615 event->set_timestamp_delta_us(10); // absolute: 1010.
1616 event->set_thread_time_delta_us(5); // absolute: 2005.
1617 event->add_category_iids(1);
1618 auto* legacy_event = event->set_legacy_event();
1619 legacy_event->set_name_iid(1);
1620 legacy_event->set_phase('B');
1621
1622 auto* interned_data = packet->set_interned_data();
1623 auto cat1 = interned_data->add_event_categories();
1624 cat1->set_iid(1);
1625 cat1->set_name("cat1");
1626 auto ev1 = interned_data->add_event_names();
1627 ev1->set_iid(1);
1628 ev1->set_name("ev1");
1629 }
1630 {
1631 auto* packet = trace_.add_packet();
1632 packet->set_trusted_packet_sequence_id(2);
1633 packet->set_incremental_state_cleared(true);
1634 auto* thread_desc = packet->set_thread_descriptor();
1635 thread_desc->set_pid(15);
1636 thread_desc->set_tid(17);
1637 thread_desc->set_reference_timestamp_us(995);
1638 thread_desc->set_reference_thread_time_us(3000);
1639 }
1640 {
1641 auto* packet = trace_.add_packet();
1642 packet->set_trusted_packet_sequence_id(2);
1643 auto* event = packet->set_track_event();
1644 event->set_timestamp_delta_us(10); // absolute: 1005.
1645 event->set_thread_time_delta_us(5); // absolute: 3005.
1646 event->add_category_iids(1);
1647 auto* legacy_event = event->set_legacy_event();
1648 legacy_event->set_name_iid(1);
1649 legacy_event->set_phase('B');
1650
1651 auto* interned_data = packet->set_interned_data();
1652 auto cat1 = interned_data->add_event_categories();
1653 cat1->set_iid(1);
1654 cat1->set_name("cat1");
1655 auto ev2 = interned_data->add_event_names();
1656 ev2->set_iid(1);
1657 ev2->set_name("ev2");
1658 }
1659 {
1660 auto* packet = trace_.add_packet();
1661 packet->set_trusted_packet_sequence_id(1);
1662 auto* event = packet->set_track_event();
1663 event->set_timestamp_delta_us(10); // absolute: 1020.
1664 event->set_thread_time_delta_us(5); // absolute: 2010.
1665 event->add_category_iids(1);
1666 auto* legacy_event = event->set_legacy_event();
1667 legacy_event->set_name_iid(1);
1668 legacy_event->set_phase('E');
1669 }
1670 {
1671 auto* packet = trace_.add_packet();
1672 packet->set_trusted_packet_sequence_id(2);
1673 auto* event = packet->set_track_event();
1674 event->set_timestamp_delta_us(10); // absolute: 1015.
1675 event->set_thread_time_delta_us(5); // absolute: 3015.
1676 event->add_category_iids(1);
1677 auto* legacy_event = event->set_legacy_event();
1678 legacy_event->set_name_iid(1);
1679 legacy_event->set_phase('E');
1680 }
1681
1682 Tokenize();
1683
1684 EXPECT_CALL(*process_, UpdateThread(16, 15))
1685 .WillRepeatedly(Return(1));
1686 EXPECT_CALL(*process_, UpdateThread(17, 15))
1687 .WillRepeatedly(Return(2));
1688
1689 tables::ThreadTable::Row t1(16);
1690 t1.upid = 1u;
1691 storage_->mutable_thread_table()->Insert(t1);
1692
1693 tables::ThreadTable::Row t2(17);
1694 t2.upid = 1u;
1695 storage_->mutable_thread_table()->Insert(t2);
1696
1697 StringId cat_1 = storage_->InternString("cat1");
1698 StringId ev_2 = storage_->InternString("ev2");
1699 StringId ev_1 = storage_->InternString("ev1");
1700
1701 constexpr TrackId thread_2_track{0u};
1702 constexpr TrackId thread_1_track{1u};
1703 InSequence in_sequence; // Below slices should be sorted by timestamp.
1704
1705 EXPECT_CALL(*slice_, Begin(1005000, thread_2_track, cat_1, ev_2, _));
1706 EXPECT_CALL(*slice_, Begin(1010000, thread_1_track, cat_1, ev_1, _));
1707 EXPECT_CALL(*slice_, End(1015000, thread_2_track, cat_1, ev_2, _));
1708 EXPECT_CALL(*slice_, End(1020000, thread_1_track, cat_1, ev_1, _));
1709
1710 context_.sorter->ExtractEventsForced();
1711 }
1712
TEST_F(ProtoTraceParserTest,TrackEventWithDebugAnnotations)1713 TEST_F(ProtoTraceParserTest, TrackEventWithDebugAnnotations) {
1714 context_.sorter.reset(new TraceSorter(
1715 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
1716 MockBoundInserter inserter;
1717
1718 {
1719 auto* packet = trace_.add_packet();
1720 packet->set_trusted_packet_sequence_id(1);
1721 packet->set_incremental_state_cleared(true);
1722 auto* thread_desc = packet->set_thread_descriptor();
1723 thread_desc->set_pid(15);
1724 thread_desc->set_tid(16);
1725 thread_desc->set_reference_timestamp_us(1000);
1726 thread_desc->set_reference_thread_time_us(2000);
1727 }
1728 {
1729 auto* packet = trace_.add_packet();
1730 packet->set_trusted_packet_sequence_id(1);
1731 auto* event = packet->set_track_event();
1732 event->set_timestamp_delta_us(10); // absolute: 1010.
1733 event->set_thread_time_delta_us(5); // absolute: 2005.
1734 event->add_category_iids(1);
1735 auto* annotation1 = event->add_debug_annotations();
1736 annotation1->set_name_iid(1);
1737 annotation1->set_uint_value(10u);
1738 auto* annotation2 = event->add_debug_annotations();
1739 annotation2->set_name_iid(2);
1740 auto* nested = annotation2->set_nested_value();
1741 nested->set_nested_type(protos::pbzero::DebugAnnotation::NestedValue::DICT);
1742 nested->add_dict_keys("child1");
1743 nested->add_dict_keys("child2");
1744 auto* child1 = nested->add_dict_values();
1745 child1->set_nested_type(
1746 protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
1747 child1->set_bool_value(true);
1748 auto* child2 = nested->add_dict_values();
1749 child2->set_nested_type(
1750 protos::pbzero::DebugAnnotation::NestedValue::ARRAY);
1751 auto* child21 = child2->add_array_values();
1752 child21->set_nested_type(
1753 protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
1754 child21->set_string_value("child21");
1755 auto* child22 = child2->add_array_values();
1756 child22->set_nested_type(
1757 protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
1758 child22->set_double_value(2.2);
1759 auto* child23 = child2->add_array_values();
1760 child23->set_nested_type(
1761 protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
1762 child23->set_int_value(23);
1763 auto* legacy_event = event->set_legacy_event();
1764 legacy_event->set_name_iid(1);
1765 legacy_event->set_phase('B');
1766
1767 auto* interned_data = packet->set_interned_data();
1768 auto cat1 = interned_data->add_event_categories();
1769 cat1->set_iid(1);
1770 cat1->set_name("cat1");
1771 auto ev1 = interned_data->add_event_names();
1772 ev1->set_iid(1);
1773 ev1->set_name("ev1");
1774 auto an1 = interned_data->add_debug_annotation_names();
1775 an1->set_iid(1);
1776 an1->set_name("an1");
1777 auto an2 = interned_data->add_debug_annotation_names();
1778 an2->set_iid(2);
1779 an2->set_name("an2");
1780 }
1781 {
1782 auto* packet = trace_.add_packet();
1783 packet->set_trusted_packet_sequence_id(1);
1784 auto* event = packet->set_track_event();
1785 event->set_timestamp_delta_us(10); // absolute: 1020.
1786 event->set_thread_time_delta_us(5); // absolute: 2010.
1787 event->add_category_iids(1);
1788 auto* annotation3 = event->add_debug_annotations();
1789 annotation3->set_name_iid(3);
1790 annotation3->set_int_value(-3);
1791 auto* annotation4 = event->add_debug_annotations();
1792 annotation4->set_name_iid(4);
1793 annotation4->set_bool_value(true);
1794 auto* annotation5 = event->add_debug_annotations();
1795 annotation5->set_name_iid(5);
1796 annotation5->set_double_value(-5.5);
1797 auto* annotation6 = event->add_debug_annotations();
1798 annotation6->set_name_iid(6);
1799 annotation6->set_pointer_value(20u);
1800 auto* annotation7 = event->add_debug_annotations();
1801 annotation7->set_name_iid(7);
1802 annotation7->set_string_value("val7");
1803 auto* annotation8 = event->add_debug_annotations();
1804 annotation8->set_name_iid(8);
1805 annotation8->set_legacy_json_value(
1806 "{\"val8\": {\"a\": 42, \"b\": \"val8b\"}, \"arr8\": [1, 2, 3]}");
1807 auto* annotation9 = event->add_debug_annotations();
1808 annotation9->set_name_iid(9);
1809 annotation9->set_int_value(15);
1810 auto* legacy_event = event->set_legacy_event();
1811 legacy_event->set_name_iid(1);
1812 legacy_event->set_phase('E');
1813
1814 auto* interned_data = packet->set_interned_data();
1815 auto an3 = interned_data->add_debug_annotation_names();
1816 an3->set_iid(3);
1817 an3->set_name("an3");
1818 auto an4 = interned_data->add_debug_annotation_names();
1819 an4->set_iid(4);
1820 an4->set_name("an4");
1821 auto an5 = interned_data->add_debug_annotation_names();
1822 an5->set_iid(5);
1823 an5->set_name("an5");
1824 auto an6 = interned_data->add_debug_annotation_names();
1825 an6->set_iid(6);
1826 an6->set_name("an6");
1827 auto an7 = interned_data->add_debug_annotation_names();
1828 an7->set_iid(7);
1829 an7->set_name("an7");
1830 auto an8 = interned_data->add_debug_annotation_names();
1831 an8->set_iid(8);
1832 an8->set_name("an8");
1833 auto an9 = interned_data->add_debug_annotation_names();
1834 an9->set_iid(9);
1835 an9->set_name("an8.foo");
1836 }
1837
1838 Tokenize();
1839
1840 EXPECT_CALL(*process_, UpdateThread(16, 15))
1841 .WillRepeatedly(Return(1));
1842
1843 tables::ThreadTable::Row row(16);
1844 row.upid = 1u;
1845 storage_->mutable_thread_table()->Insert(row);
1846
1847 StringId cat_1 = storage_->InternString("cat1");
1848 StringId ev_1 = storage_->InternString("ev1");
1849 StringId debug_an_1 = storage_->InternString("debug.an1");
1850 StringId debug_an_2_child_1 = storage_->InternString("debug.an2.child1");
1851 StringId debug_an_2_child_2 = storage_->InternString("debug.an2.child2");
1852 StringId debug_an_2_child_2_0 = storage_->InternString("debug.an2.child2[0]");
1853 StringId child21 = storage_->InternString("child21");
1854 StringId debug_an_2_child_2_1 = storage_->InternString("debug.an2.child2[1]");
1855 StringId debug_an_2_child_2_2 = storage_->InternString("debug.an2.child2[2]");
1856 StringId debug_an_3 = storage_->InternString("debug.an3");
1857 StringId debug_an_4 = storage_->InternString("debug.an4");
1858 StringId debug_an_5 = storage_->InternString("debug.an5");
1859 StringId debug_an_6 = storage_->InternString("debug.an6");
1860 StringId debug_an_7 = storage_->InternString("debug.an7");
1861 StringId val_7 = storage_->InternString("val7");
1862 StringId debug_an_8_val8_a = storage_->InternString("debug.an8.val8.a");
1863 StringId debug_an_8_val8_b = storage_->InternString("debug.an8.val8.b");
1864 StringId val_8b = storage_->InternString("val8b");
1865 StringId debug_an_8_arr8 = storage_->InternString("debug.an8.arr8");
1866 StringId debug_an_8_arr8_0 = storage_->InternString("debug.an8.arr8[0]");
1867 StringId debug_an_8_arr8_1 = storage_->InternString("debug.an8.arr8[1]");
1868 StringId debug_an_8_arr8_2 = storage_->InternString("debug.an8.arr8[2]");
1869 StringId debug_an_8_foo = storage_->InternString("debug.an8_foo");
1870
1871 constexpr TrackId track{0u};
1872
1873 EXPECT_CALL(*slice_, Begin(1010000, track, cat_1, ev_1, _))
1874 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(1u)));
1875 EXPECT_CALL(inserter, AddArg(debug_an_1, debug_an_1,
1876 Variadic::UnsignedInteger(10u), _));
1877
1878 EXPECT_CALL(inserter, AddArg(debug_an_2_child_1, debug_an_2_child_1,
1879 Variadic::Boolean(true), _));
1880
1881 EXPECT_CALL(inserter, AddArg(debug_an_2_child_2, debug_an_2_child_2_0,
1882 Variadic::String(child21), _));
1883
1884 EXPECT_CALL(inserter, AddArg(debug_an_2_child_2, debug_an_2_child_2_1,
1885 Variadic::Real(2.2), _));
1886
1887 EXPECT_CALL(inserter, AddArg(debug_an_2_child_2, debug_an_2_child_2_2,
1888 Variadic::Integer(23), _));
1889
1890 EXPECT_CALL(*slice_, End(1020000, track, cat_1, ev_1, _))
1891 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(1u)));
1892
1893 EXPECT_CALL(inserter,
1894 AddArg(debug_an_3, debug_an_3, Variadic::Integer(-3), _));
1895 EXPECT_CALL(inserter,
1896 AddArg(debug_an_4, debug_an_4, Variadic::Boolean(true), _));
1897 EXPECT_CALL(inserter,
1898 AddArg(debug_an_5, debug_an_5, Variadic::Real(-5.5), _));
1899 EXPECT_CALL(inserter,
1900 AddArg(debug_an_6, debug_an_6, Variadic::Pointer(20u), _));
1901 EXPECT_CALL(inserter,
1902 AddArg(debug_an_7, debug_an_7, Variadic::String(val_7), _));
1903 EXPECT_CALL(inserter, AddArg(debug_an_8_val8_a, debug_an_8_val8_a,
1904 Variadic::Integer(42), _));
1905 EXPECT_CALL(inserter, AddArg(debug_an_8_val8_b, debug_an_8_val8_b,
1906 Variadic::String(val_8b), _));
1907 EXPECT_CALL(inserter, AddArg(debug_an_8_arr8, debug_an_8_arr8_0,
1908 Variadic::Integer(1), _));
1909 EXPECT_CALL(inserter, AddArg(debug_an_8_arr8, debug_an_8_arr8_1,
1910 Variadic::Integer(2), _));
1911 EXPECT_CALL(inserter, AddArg(debug_an_8_arr8, debug_an_8_arr8_2,
1912 Variadic::Integer(3), _));
1913 EXPECT_CALL(inserter,
1914 AddArg(debug_an_8_foo, debug_an_8_foo, Variadic::Integer(15), _));
1915
1916 context_.sorter->ExtractEventsForced();
1917 }
1918
TEST_F(ProtoTraceParserTest,TrackEventWithTaskExecution)1919 TEST_F(ProtoTraceParserTest, TrackEventWithTaskExecution) {
1920 context_.sorter.reset(new TraceSorter(
1921 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
1922
1923 {
1924 auto* packet = trace_.add_packet();
1925 packet->set_trusted_packet_sequence_id(1);
1926 packet->set_incremental_state_cleared(true);
1927 auto* thread_desc = packet->set_thread_descriptor();
1928 thread_desc->set_pid(15);
1929 thread_desc->set_tid(16);
1930 thread_desc->set_reference_timestamp_us(1000);
1931 thread_desc->set_reference_thread_time_us(2000);
1932 }
1933 {
1934 auto* packet = trace_.add_packet();
1935 packet->set_trusted_packet_sequence_id(1);
1936 auto* event = packet->set_track_event();
1937 event->set_timestamp_delta_us(10); // absolute: 1010.
1938 event->set_thread_time_delta_us(5); // absolute: 2005.
1939 event->add_category_iids(1);
1940 auto* task_execution = event->set_task_execution();
1941 task_execution->set_posted_from_iid(1);
1942 auto* legacy_event = event->set_legacy_event();
1943 legacy_event->set_name_iid(1);
1944 legacy_event->set_phase('B');
1945
1946 auto* interned_data = packet->set_interned_data();
1947 auto cat1 = interned_data->add_event_categories();
1948 cat1->set_iid(1);
1949 cat1->set_name("cat1");
1950 auto ev1 = interned_data->add_event_names();
1951 ev1->set_iid(1);
1952 ev1->set_name("ev1");
1953 auto loc1 = interned_data->add_source_locations();
1954 loc1->set_iid(1);
1955 loc1->set_file_name("file1");
1956 loc1->set_function_name("func1");
1957 loc1->set_line_number(42);
1958 }
1959
1960 Tokenize();
1961
1962 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillRepeatedly(Return(1));
1963
1964 tables::ThreadTable::Row row(16);
1965 row.upid = 1u;
1966 storage_->mutable_thread_table()->Insert(row);
1967
1968 constexpr TrackId track{0u};
1969
1970 StringId cat_1 = storage_->InternString("cat1");
1971 StringId ev_1 = storage_->InternString("ev1");
1972 StringId file_1 = storage_->InternString("file1");
1973 StringId func_1 = storage_->InternString("func1");
1974
1975 InSequence in_sequence; // Below slices should be sorted by timestamp.
1976
1977 MockBoundInserter inserter;
1978 EXPECT_CALL(*slice_, Begin(1010000, track, cat_1, ev_1, _))
1979 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(1u)));
1980 EXPECT_CALL(inserter, AddArg(_, _, Variadic::String(file_1), _));
1981 EXPECT_CALL(inserter, AddArg(_, _, Variadic::String(func_1), _));
1982 EXPECT_CALL(inserter, AddArg(_, _, Variadic::UnsignedInteger(42), _));
1983
1984 context_.sorter->ExtractEventsForced();
1985 }
1986
TEST_F(ProtoTraceParserTest,TrackEventWithLogMessage)1987 TEST_F(ProtoTraceParserTest, TrackEventWithLogMessage) {
1988 context_.sorter.reset(new TraceSorter(
1989 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
1990
1991 {
1992 auto* packet = trace_.add_packet();
1993 packet->set_trusted_packet_sequence_id(1);
1994 packet->set_incremental_state_cleared(true);
1995 auto* thread_desc = packet->set_thread_descriptor();
1996 thread_desc->set_pid(15);
1997 thread_desc->set_tid(16);
1998 thread_desc->set_reference_timestamp_us(1000);
1999 thread_desc->set_reference_thread_time_us(2000);
2000 }
2001 {
2002 auto* packet = trace_.add_packet();
2003 packet->set_trusted_packet_sequence_id(1);
2004 auto* event = packet->set_track_event();
2005 event->set_timestamp_delta_us(10); // absolute: 1010.
2006 event->set_thread_time_delta_us(5); // absolute: 2005.
2007 event->add_category_iids(1);
2008
2009 auto* log_message = event->set_log_message();
2010 log_message->set_body_iid(1);
2011 log_message->set_source_location_iid(1);
2012
2013 auto* legacy_event = event->set_legacy_event();
2014 legacy_event->set_name_iid(1);
2015 legacy_event->set_phase('I');
2016
2017 auto* interned_data = packet->set_interned_data();
2018 auto cat1 = interned_data->add_event_categories();
2019 cat1->set_iid(1);
2020 cat1->set_name("cat1");
2021
2022 auto ev1 = interned_data->add_event_names();
2023 ev1->set_iid(1);
2024 ev1->set_name("ev1");
2025
2026 auto body = interned_data->add_log_message_body();
2027 body->set_iid(1);
2028 body->set_body("body1");
2029
2030 auto loc1 = interned_data->add_source_locations();
2031 loc1->set_iid(1);
2032 loc1->set_file_name("file1");
2033 loc1->set_function_name("func1");
2034 loc1->set_line_number(1);
2035 }
2036
2037 Tokenize();
2038
2039 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillRepeatedly(Return(1));
2040
2041 tables::ThreadTable::Row row(16);
2042 row.upid = 1u;
2043 storage_->mutable_thread_table()->Insert(row);
2044
2045 StringId cat_1 = storage_->InternString("cat1");
2046 StringId ev_1 = storage_->InternString("ev1");
2047 StringId body_1 = storage_->InternString("body1");
2048
2049 constexpr TrackId track{0};
2050 InSequence in_sequence; // Below slices should be sorted by timestamp.
2051
2052 MockBoundInserter inserter;
2053 EXPECT_CALL(*slice_, Scoped(1010000, track, cat_1, ev_1, 0, _))
2054 .WillOnce(DoAll(InvokeArgument<5>(&inserter), Return(1u)));
2055
2056 // Call with logMessageBody (body1 in this case).
2057 EXPECT_CALL(inserter, AddArg(_, _, Variadic::String(body_1), _));
2058
2059 context_.sorter->ExtractEventsForced();
2060
2061 EXPECT_GT(context_.storage->android_log_table().row_count(), 0u);
2062 EXPECT_EQ(context_.storage->android_log_table().ts()[0], 1010000);
2063 EXPECT_EQ(context_.storage->android_log_table().msg()[0], body_1);
2064 }
2065
TEST_F(ProtoTraceParserTest,TrackEventParseLegacyEventIntoRawTable)2066 TEST_F(ProtoTraceParserTest, TrackEventParseLegacyEventIntoRawTable) {
2067 context_.sorter.reset(new TraceSorter(
2068 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
2069
2070 {
2071 auto* packet = trace_.add_packet();
2072 packet->set_trusted_packet_sequence_id(1);
2073 packet->set_incremental_state_cleared(true);
2074 auto* thread_desc = packet->set_thread_descriptor();
2075 thread_desc->set_pid(15);
2076 thread_desc->set_tid(16);
2077 thread_desc->set_reference_timestamp_us(1000);
2078 thread_desc->set_reference_thread_time_us(2000);
2079 }
2080 {
2081 auto* packet = trace_.add_packet();
2082 packet->set_trusted_packet_sequence_id(1);
2083 auto* event = packet->set_track_event();
2084 event->set_timestamp_delta_us(10); // absolute: 1010.
2085 event->set_thread_time_delta_us(5); // absolute: 2005.
2086 event->add_category_iids(1);
2087
2088 auto* legacy_event = event->set_legacy_event();
2089 legacy_event->set_name_iid(1);
2090 // Represents a phase that isn't parsed into regular trace processor tables.
2091 legacy_event->set_phase('?');
2092 legacy_event->set_duration_us(23);
2093 legacy_event->set_thread_duration_us(15);
2094 legacy_event->set_global_id(99u);
2095 legacy_event->set_id_scope("scope1");
2096 legacy_event->set_use_async_tts('?');
2097 legacy_event->set_bind_id(98);
2098 legacy_event->set_bind_to_enclosing(true);
2099 legacy_event->set_flow_direction(
2100 protos::pbzero::TrackEvent::LegacyEvent::FLOW_INOUT);
2101
2102 auto* annotation1 = event->add_debug_annotations();
2103 annotation1->set_name_iid(1);
2104 annotation1->set_uint_value(10u);
2105
2106 auto* interned_data = packet->set_interned_data();
2107 auto cat1 = interned_data->add_event_categories();
2108 cat1->set_iid(1);
2109 cat1->set_name("cat1");
2110 auto ev1 = interned_data->add_event_names();
2111 ev1->set_iid(1);
2112 ev1->set_name("ev1");
2113 auto an1 = interned_data->add_debug_annotation_names();
2114 an1->set_iid(1);
2115 an1->set_name("an1");
2116 }
2117
2118 Tokenize();
2119
2120 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillRepeatedly(Return(1));
2121
2122 tables::ThreadTable::Row row(16);
2123 row.upid = 1u;
2124 storage_->mutable_thread_table()->Insert(row);
2125
2126 StringId cat_1 = storage_->InternString("cat1");
2127 StringId ev_1 = storage_->InternString("ev1");
2128 StringId scope_1 = storage_->InternString("scope1");
2129 StringId question = storage_->InternString("?");
2130 StringId debug_an_1 = storage_->InternString("debug.an1");
2131
2132 context_.sorter->ExtractEventsForced();
2133
2134 ::testing::Mock::VerifyAndClearExpectations(storage_);
2135
2136 // Verify raw_table and args contents.
2137 const auto& raw_table = storage_->raw_table();
2138 EXPECT_EQ(raw_table.row_count(), 1u);
2139 EXPECT_EQ(raw_table.ts()[0], 1010000);
2140 EXPECT_EQ(raw_table.name()[0],
2141 storage_->InternString("track_event.legacy_event"));
2142 EXPECT_EQ(raw_table.cpu()[0], 0u);
2143 EXPECT_EQ(raw_table.utid()[0], 1u);
2144 EXPECT_EQ(raw_table.arg_set_id()[0], 1u);
2145
2146 EXPECT_GE(storage_->arg_table().row_count(), 13u);
2147
2148 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.category"),
2149 Variadic::String(cat_1)));
2150 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.name"),
2151 Variadic::String(ev_1)));
2152 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.phase"),
2153 Variadic::String(question)));
2154 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.duration_ns"),
2155 Variadic::Integer(23000)));
2156 EXPECT_TRUE(HasArg(1u,
2157 storage_->InternString("legacy_event.thread_timestamp_ns"),
2158 Variadic::Integer(2005000)));
2159 EXPECT_TRUE(HasArg(1u,
2160 storage_->InternString("legacy_event.thread_duration_ns"),
2161 Variadic::Integer(15000)));
2162 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.use_async_tts"),
2163 Variadic::Boolean(true)));
2164 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.global_id"),
2165 Variadic::UnsignedInteger(99u)));
2166 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.id_scope"),
2167 Variadic::String(scope_1)));
2168 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.bind_id"),
2169 Variadic::UnsignedInteger(98u)));
2170 EXPECT_TRUE(HasArg(1u,
2171 storage_->InternString("legacy_event.bind_to_enclosing"),
2172 Variadic::Boolean(true)));
2173 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.flow_direction"),
2174 Variadic::String(storage_->InternString("inout"))));
2175 EXPECT_TRUE(HasArg(1u, debug_an_1, Variadic::UnsignedInteger(10u)));
2176 }
2177
TEST_F(ProtoTraceParserTest,TrackEventLegacyTimestampsWithClockSnapshot)2178 TEST_F(ProtoTraceParserTest, TrackEventLegacyTimestampsWithClockSnapshot) {
2179 context_.sorter.reset(new TraceSorter(
2180 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
2181
2182 clock_->AddSnapshot(
2183 {{protos::pbzero::ClockSnapshot::Clock::BOOTTIME, 0},
2184 {protos::pbzero::ClockSnapshot::Clock::MONOTONIC, 1000000}});
2185
2186 {
2187 auto* packet = trace_.add_packet();
2188 packet->set_trusted_packet_sequence_id(1);
2189 packet->set_incremental_state_cleared(true);
2190 auto* thread_desc = packet->set_thread_descriptor();
2191 thread_desc->set_pid(15);
2192 thread_desc->set_tid(16);
2193 thread_desc->set_reference_timestamp_us(1000); // MONOTONIC.
2194 }
2195 {
2196 auto* packet = trace_.add_packet();
2197 packet->set_trusted_packet_sequence_id(1);
2198 auto* event = packet->set_track_event();
2199 event->set_timestamp_delta_us(10); // absolute: 1010 (mon), 10 (boot).
2200 event->add_category_iids(1);
2201 event->set_type(protos::pbzero::TrackEvent::TYPE_SLICE_BEGIN);
2202 auto* legacy_event = event->set_legacy_event();
2203 legacy_event->set_name_iid(1);
2204 }
2205
2206 Tokenize();
2207
2208 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillRepeatedly(Return(1));
2209
2210 tables::ThreadTable::Row row(16);
2211 row.upid = 1u;
2212 storage_->mutable_thread_table()->Insert(row);
2213
2214 constexpr TrackId track{0u};
2215 InSequence in_sequence; // Below slices should be sorted by timestamp.
2216 StringId unknown_cat = storage_->InternString("unknown(1)");
2217
2218 // Timestamp should be adjusted to trace time (BOOTTIME).
2219 EXPECT_CALL(*slice_, Begin(10000, track, unknown_cat, kNullStringId, _));
2220
2221 context_.sorter->ExtractEventsForced();
2222 }
2223
TEST_F(ProtoTraceParserTest,ParseEventWithClockIdButWithoutClockSnapshot)2224 TEST_F(ProtoTraceParserTest, ParseEventWithClockIdButWithoutClockSnapshot) {
2225 context_.sorter.reset(new TraceSorter(
2226 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
2227
2228 {
2229 auto* packet = trace_.add_packet();
2230 packet->set_timestamp(1000);
2231 packet->set_timestamp_clock_id(3);
2232 packet->set_trusted_packet_sequence_id(1);
2233 auto* bundle = packet->set_chrome_events();
2234 auto* metadata = bundle->add_metadata();
2235 metadata->set_name("test");
2236 metadata->set_int_value(23);
2237 }
2238
2239 util::Status status = Tokenize();
2240 EXPECT_TRUE(status.ok());
2241 context_.sorter->ExtractEventsForced();
2242
2243 // Metadata should have created a raw event.
2244 const auto& raw_table = storage_->raw_table();
2245 EXPECT_EQ(raw_table.row_count(), 1u);
2246 }
2247
TEST_F(ProtoTraceParserTest,ParseChromeMetadataEventIntoRawTable)2248 TEST_F(ProtoTraceParserTest, ParseChromeMetadataEventIntoRawTable) {
2249 static const char kStringName[] = "string_name";
2250 static const char kStringValue[] = "string_value";
2251 static const char kIntName[] = "int_name";
2252 static const int kIntValue = 123;
2253
2254 context_.sorter.reset(new TraceSorter(
2255 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
2256
2257 {
2258 auto* packet = trace_.add_packet();
2259 packet->set_timestamp(1000);
2260 packet->set_timestamp_clock_id(3);
2261 packet->set_trusted_packet_sequence_id(1);
2262 auto* bundle = packet->set_chrome_events();
2263 auto* metadata = bundle->add_metadata();
2264 metadata->set_name(kStringName);
2265 metadata->set_string_value(kStringValue);
2266 metadata = bundle->add_metadata();
2267 metadata->set_name(kIntName);
2268 metadata->set_int_value(kIntValue);
2269 }
2270
2271 Tokenize();
2272 context_.sorter->ExtractEventsForced();
2273
2274 // Verify raw_table and args contents.
2275 const auto& raw_table = storage_->raw_table();
2276 EXPECT_EQ(raw_table.row_count(), 1u);
2277 EXPECT_EQ(raw_table.name()[0],
2278 storage_->InternString("chrome_event.metadata"));
2279 EXPECT_EQ(raw_table.arg_set_id()[0], 1u);
2280
2281 EXPECT_EQ(storage_->arg_table().row_count(), 2u);
2282 EXPECT_TRUE(HasArg(1u, storage_->InternString(kStringName),
2283 Variadic::String(storage_->InternString(kStringValue))));
2284 EXPECT_TRUE(HasArg(1u, storage_->InternString(kIntName),
2285 Variadic::Integer(kIntValue)));
2286 }
2287
TEST_F(ProtoTraceParserTest,ParseChromeLegacyFtraceIntoRawTable)2288 TEST_F(ProtoTraceParserTest, ParseChromeLegacyFtraceIntoRawTable) {
2289 static const char kDataPart0[] = "aaa";
2290 static const char kDataPart1[] = "bbb";
2291 static const char kFullData[] = "aaabbb";
2292
2293 context_.sorter.reset(new TraceSorter(
2294 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
2295
2296 {
2297 auto* packet = trace_.add_packet();
2298 packet->set_trusted_packet_sequence_id(1);
2299 auto* bundle = packet->set_chrome_events();
2300 bundle->add_legacy_ftrace_output(kDataPart0);
2301 bundle->add_legacy_ftrace_output(kDataPart1);
2302 }
2303
2304 Tokenize();
2305
2306 context_.sorter->ExtractEventsForced();
2307
2308 // Verify raw_table and args contents.
2309 const auto& raw_table = storage_->raw_table();
2310 EXPECT_EQ(raw_table.row_count(), 1u);
2311 EXPECT_EQ(raw_table.name()[0],
2312 storage_->InternString("chrome_event.legacy_system_trace"));
2313 EXPECT_EQ(raw_table.arg_set_id()[0], 1u);
2314
2315 EXPECT_EQ(storage_->arg_table().row_count(), 1u);
2316 EXPECT_TRUE(HasArg(1u, storage_->InternString("data"),
2317 Variadic::String(storage_->InternString(kFullData))));
2318 }
2319
TEST_F(ProtoTraceParserTest,ParseChromeLegacyJsonIntoRawTable)2320 TEST_F(ProtoTraceParserTest, ParseChromeLegacyJsonIntoRawTable) {
2321 static const char kUserTraceEvent[] = "{\"user\":1}";
2322
2323 context_.sorter.reset(new TraceSorter(
2324 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
2325
2326 {
2327 auto* packet = trace_.add_packet();
2328 packet->set_trusted_packet_sequence_id(1);
2329 auto* bundle = packet->set_chrome_events();
2330 auto* user_trace = bundle->add_legacy_json_trace();
2331 user_trace->set_type(protos::pbzero::ChromeLegacyJsonTrace::USER_TRACE);
2332 user_trace->set_data(kUserTraceEvent);
2333 }
2334
2335 Tokenize();
2336
2337 context_.sorter->ExtractEventsForced();
2338
2339 // Verify raw_table and args contents.
2340 const auto& raw_table = storage_->raw_table();
2341 EXPECT_EQ(raw_table.row_count(), 1u);
2342 EXPECT_EQ(raw_table.name()[0],
2343 storage_->InternString("chrome_event.legacy_user_trace"));
2344 EXPECT_EQ(raw_table.arg_set_id()[0], 1u);
2345
2346 EXPECT_EQ(storage_->arg_table().row_count(), 1u);
2347 EXPECT_TRUE(
2348 HasArg(1u, storage_->InternString("data"),
2349 Variadic::String(storage_->InternString(kUserTraceEvent))));
2350 }
2351
TEST_F(ProtoTraceParserTest,LoadChromeBenchmarkMetadata)2352 TEST_F(ProtoTraceParserTest, LoadChromeBenchmarkMetadata) {
2353 static const char kName[] = "name";
2354 static const char kTag1[] = "tag1";
2355 static const char kTag2[] = "tag2";
2356
2357 context_.sorter.reset(new TraceSorter(
2358 CreateParser(), std::numeric_limits<int64_t>::max() /*window size*/));
2359
2360 auto* metadata = trace_.add_packet()->set_chrome_benchmark_metadata();
2361 metadata->set_benchmark_name(kName);
2362 metadata->add_story_tags(kTag1);
2363 metadata->add_story_tags(kTag2);
2364
2365 Tokenize();
2366
2367 StringId name_1 = storage_->InternString(kName);
2368 StringId tag_1 = storage_->InternString(kTag1);
2369 StringId tag_2 = storage_->InternString(kTag2);
2370
2371 StringId benchmark_id = *storage_->string_pool().GetId(
2372 metadata::kNames[metadata::benchmark_name]);
2373 StringId tags_id = *storage_->string_pool().GetId(
2374 metadata::kNames[metadata::benchmark_story_tags]);
2375
2376 context_.sorter->ExtractEventsForced();
2377
2378 const auto& meta_keys = storage_->metadata_table().name();
2379 const auto& meta_values = storage_->metadata_table().str_value();
2380 EXPECT_EQ(storage_->metadata_table().row_count(), 3u);
2381
2382 std::vector<std::pair<StringId, StringId>> meta_entries;
2383 for (uint32_t i = 0; i < storage_->metadata_table().row_count(); i++) {
2384 meta_entries.emplace_back(std::make_pair(meta_keys[i], meta_values[i]));
2385 }
2386 EXPECT_THAT(meta_entries,
2387 UnorderedElementsAreArray({std::make_pair(benchmark_id, name_1),
2388 std::make_pair(tags_id, tag_1),
2389 std::make_pair(tags_id, tag_2)}));
2390 }
2391
TEST_F(ProtoTraceParserTest,AndroidPackagesList)2392 TEST_F(ProtoTraceParserTest, AndroidPackagesList) {
2393 auto* packet = trace_.add_packet();
2394 auto* pkg_list = packet->set_packages_list();
2395
2396 pkg_list->set_read_error(false);
2397 pkg_list->set_parse_error(true);
2398 {
2399 auto* pkg = pkg_list->add_packages();
2400 pkg->set_name("com.test.app");
2401 pkg->set_uid(1000);
2402 pkg->set_debuggable(false);
2403 pkg->set_profileable_from_shell(true);
2404 pkg->set_version_code(42);
2405 }
2406 {
2407 auto* pkg = pkg_list->add_packages();
2408 pkg->set_name("com.test.app2");
2409 pkg->set_uid(1001);
2410 pkg->set_debuggable(false);
2411 pkg->set_profileable_from_shell(false);
2412 pkg->set_version_code(43);
2413 }
2414
2415 Tokenize();
2416
2417 // Packet-level errors reflected in stats storage.
2418 const auto& stats = context_.storage->stats();
2419 EXPECT_FALSE(stats[stats::packages_list_has_read_errors].value);
2420 EXPECT_TRUE(stats[stats::packages_list_has_parse_errors].value);
2421
2422 // Expect two metadata rows, each with an int_value of a separate arg set id.
2423 // The relevant arg sets have the info about the packages. To simplify test
2424 // structure, make an assumption that metadata storage is filled in in the
2425 // FIFO order of seen packages.
2426 const auto& args = context_.storage->arg_table();
2427 const auto& metadata = context_.storage->metadata_table();
2428
2429 Table package_list = metadata.Filter(
2430 {metadata.name().eq(metadata::kNames[metadata::android_packages_list])});
2431 ASSERT_EQ(package_list.row_count(), 2u);
2432
2433 const Column* int_value = package_list.GetColumnByName("int_value");
2434 uint32_t first_set_id = static_cast<uint32_t>(int_value->Get(0).long_value);
2435 uint32_t second_set_id = static_cast<uint32_t>(int_value->Get(1).long_value);
2436
2437 // helper to look up arg values
2438 auto find_arg = [&args, this](ArgSetId set_id, const char* arg_name) {
2439 for (uint32_t i = 0; i < args.row_count(); i++) {
2440 if (args.arg_set_id()[i] == set_id &&
2441 args.key()[i] == storage_->InternString(arg_name))
2442 return storage_->GetArgValue(i);
2443 }
2444 PERFETTO_FATAL("Didn't find expected argument");
2445 };
2446
2447 auto first_name_id = find_arg(first_set_id, "name").string_value;
2448 EXPECT_STREQ(storage_->GetString(first_name_id).c_str(), "com.test.app");
2449 EXPECT_EQ(find_arg(first_set_id, "uid").uint_value, 1000u);
2450 EXPECT_EQ(find_arg(first_set_id, "debuggable").bool_value, false);
2451 EXPECT_EQ(find_arg(first_set_id, "profileable_from_shell").bool_value, true);
2452 EXPECT_EQ(find_arg(first_set_id, "version_code").int_value, 42);
2453
2454 auto second_name_id = find_arg(second_set_id, "name").string_value;
2455 EXPECT_STREQ(storage_->GetString(second_name_id).c_str(), "com.test.app2");
2456 EXPECT_EQ(find_arg(second_set_id, "uid").uint_value, 1001u);
2457 EXPECT_EQ(find_arg(second_set_id, "debuggable").bool_value, false);
2458 EXPECT_EQ(find_arg(second_set_id, "profileable_from_shell").bool_value,
2459 false);
2460 EXPECT_EQ(find_arg(second_set_id, "version_code").int_value, 43);
2461 }
2462
TEST_F(ProtoTraceParserTest,ParseCPUProfileSamplesIntoTable)2463 TEST_F(ProtoTraceParserTest, ParseCPUProfileSamplesIntoTable) {
2464 {
2465 auto* packet = trace_.add_packet();
2466 packet->set_trusted_packet_sequence_id(1);
2467 packet->set_incremental_state_cleared(true);
2468
2469 auto* thread_desc = packet->set_thread_descriptor();
2470 thread_desc->set_pid(15);
2471 thread_desc->set_tid(16);
2472 thread_desc->set_reference_timestamp_us(1);
2473 thread_desc->set_reference_thread_time_us(2);
2474
2475 auto* interned_data = packet->set_interned_data();
2476
2477 auto mapping = interned_data->add_mappings();
2478 mapping->set_iid(1);
2479 mapping->set_build_id(1);
2480
2481 auto build_id = interned_data->add_build_ids();
2482 build_id->set_iid(1);
2483 build_id->set_str("3BBCFBD372448A727265C3E7C4D954F91");
2484
2485 auto frame = interned_data->add_frames();
2486 frame->set_iid(1);
2487 frame->set_rel_pc(0x42);
2488 frame->set_mapping_id(1);
2489
2490 auto frame2 = interned_data->add_frames();
2491 frame2->set_iid(2);
2492 frame2->set_rel_pc(0x4242);
2493 frame2->set_mapping_id(1);
2494
2495 auto callstack = interned_data->add_callstacks();
2496 callstack->set_iid(1);
2497 callstack->add_frame_ids(1);
2498
2499 auto callstack2 = interned_data->add_callstacks();
2500 callstack2->set_iid(42);
2501 callstack2->add_frame_ids(2);
2502 }
2503
2504 {
2505 auto* packet = trace_.add_packet();
2506 packet->set_trusted_packet_sequence_id(1);
2507
2508 auto* samples = packet->set_streaming_profile_packet();
2509 samples->add_callstack_iid(42);
2510 samples->add_timestamp_delta_us(10);
2511
2512 samples->add_callstack_iid(1);
2513 samples->add_timestamp_delta_us(15);
2514 }
2515
2516 {
2517 auto* packet = trace_.add_packet();
2518 packet->set_trusted_packet_sequence_id(1);
2519 auto* samples = packet->set_streaming_profile_packet();
2520
2521 samples->add_callstack_iid(42);
2522 samples->add_timestamp_delta_us(42);
2523 }
2524
2525 EXPECT_CALL(*process_, UpdateThread(16, 15))
2526 .WillRepeatedly(Return(1));
2527
2528 Tokenize();
2529
2530 // Verify cpu_profile_samples.
2531 const auto& samples = storage_->cpu_profile_stack_sample_table();
2532 EXPECT_EQ(samples.row_count(), 3u);
2533
2534 EXPECT_EQ(samples.ts()[0], 11000);
2535 EXPECT_EQ(samples.callsite_id()[0], CallsiteId{0});
2536 EXPECT_EQ(samples.utid()[0], 1u);
2537
2538 EXPECT_EQ(samples.ts()[1], 26000);
2539 EXPECT_EQ(samples.callsite_id()[1], CallsiteId{1});
2540 EXPECT_EQ(samples.utid()[1], 1u);
2541
2542 EXPECT_EQ(samples.ts()[2], 68000);
2543 EXPECT_EQ(samples.callsite_id()[2], CallsiteId{0});
2544 EXPECT_EQ(samples.utid()[2], 1u);
2545
2546 // Breakpad build_ids should not be modified/mangled.
2547 ASSERT_STREQ(
2548 context_.storage
2549 ->GetString(storage_->stack_profile_mapping_table().build_id()[0])
2550 .c_str(),
2551 "3BBCFBD372448A727265C3E7C4D954F91");
2552 }
2553
TEST_F(ProtoTraceParserTest,CPUProfileSamplesTimestampsAreClockMonotonic)2554 TEST_F(ProtoTraceParserTest, CPUProfileSamplesTimestampsAreClockMonotonic) {
2555 {
2556 auto* packet = trace_.add_packet();
2557 packet->set_trusted_packet_sequence_id(0);
2558
2559 // 1000 us monotonic == 10000 us boottime.
2560 auto* clock_snapshot = packet->set_clock_snapshot();
2561 auto* clock_boot = clock_snapshot->add_clocks();
2562 clock_boot->set_clock_id(protos::pbzero::ClockSnapshot::Clock::BOOTTIME);
2563 clock_boot->set_timestamp(10000000);
2564 auto* clock_monotonic = clock_snapshot->add_clocks();
2565 clock_monotonic->set_clock_id(
2566 protos::pbzero::ClockSnapshot::Clock::MONOTONIC);
2567 clock_monotonic->set_timestamp(1000000);
2568 }
2569
2570 {
2571 auto* packet = trace_.add_packet();
2572 packet->set_trusted_packet_sequence_id(1);
2573 packet->set_incremental_state_cleared(true);
2574
2575 auto* thread_desc = packet->set_thread_descriptor();
2576 thread_desc->set_pid(15);
2577 thread_desc->set_tid(16);
2578 thread_desc->set_reference_timestamp_us(1000);
2579 thread_desc->set_reference_thread_time_us(2000);
2580
2581 auto* interned_data = packet->set_interned_data();
2582
2583 auto mapping = interned_data->add_mappings();
2584 mapping->set_iid(1);
2585 mapping->set_build_id(1);
2586
2587 auto build_id = interned_data->add_build_ids();
2588 build_id->set_iid(1);
2589 build_id->set_str("3BBCFBD372448A727265C3E7C4D954F91");
2590
2591 auto frame = interned_data->add_frames();
2592 frame->set_iid(1);
2593 frame->set_rel_pc(0x42);
2594 frame->set_mapping_id(1);
2595
2596 auto callstack = interned_data->add_callstacks();
2597 callstack->set_iid(1);
2598 callstack->add_frame_ids(1);
2599 }
2600
2601 {
2602 auto* packet = trace_.add_packet();
2603 packet->set_trusted_packet_sequence_id(1);
2604
2605 auto* samples = packet->set_streaming_profile_packet();
2606 samples->add_callstack_iid(1);
2607 samples->add_timestamp_delta_us(15);
2608 }
2609
2610 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillRepeatedly(Return(1));
2611
2612 Tokenize();
2613
2614 const auto& samples = storage_->cpu_profile_stack_sample_table();
2615 EXPECT_EQ(samples.row_count(), 1u);
2616
2617 // Should have been translated to boottime, i.e. 10015 us absolute.
2618 EXPECT_EQ(samples.ts()[0], 10015000);
2619 EXPECT_EQ(samples.callsite_id()[0], CallsiteId{0});
2620 EXPECT_EQ(samples.utid()[0], 1u);
2621 }
2622
2623 } // namespace
2624 } // namespace trace_processor
2625 } // namespace perfetto
2626