blob: fbe326eb05f7d2a5f3009ecd0710e90a8217f9e3 [file] [log] [blame]
Lalit Maganti93b76362018-06-01 03:03:58 +01001/*
Lalit Magantic6bccda2018-06-25 11:05:24 +01002 * Copyright (C) 2018 The Android Open Source Project
Lalit Maganti93b76362018-06-01 03:03:58 +01003 *
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
Primiano Tuccid933d912018-09-04 09:15:07 +010017#include "src/trace_processor/proto_trace_tokenizer.h"
Lalit Maganti93b76362018-06-01 03:03:58 +010018
Primiano Tucci2c5488f2019-06-01 03:27:28 +010019#include "perfetto/ext/base/string_view.h"
Primiano Tuccie5f11682019-03-22 07:21:49 +000020#include "perfetto/protozero/scattered_heap_buffer.h"
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +000021#include "src/trace_processor/args_tracker.h"
Eric Seckler15ea5df2019-10-14 13:54:07 +010022#include "src/trace_processor/clock_tracker.h"
Isabelle Taylora97c5f52018-10-23 17:36:12 +010023#include "src/trace_processor/event_tracker.h"
Mikhail Khokhlovb1fe42a2019-05-23 13:58:05 +010024#include "src/trace_processor/metadata.h"
Primiano Tucci0d72a312018-08-07 14:42:45 +010025#include "src/trace_processor/process_tracker.h"
Primiano Tuccid933d912018-09-04 09:15:07 +010026#include "src/trace_processor/proto_trace_parser.h"
Eric Seckler56a007d2019-05-02 16:25:14 +010027#include "src/trace_processor/slice_tracker.h"
Oystein Eftevaag7f64c102019-08-29 10:27:31 -070028#include "src/trace_processor/stack_profile_tracker.h"
Primiano Tucci8e3da692019-06-08 08:56:01 +010029#include "src/trace_processor/systrace_parser.h"
Primiano Tuccid933d912018-09-04 09:15:07 +010030#include "src/trace_processor/trace_sorter.h"
Lalit Maganti4ea78d92019-09-20 20:20:41 +010031#include "src/trace_processor/track_tracker.h"
Mohammad Reza Zakerinasabb06d1852019-09-11 14:41:36 -040032#include "src/trace_processor/vulkan_memory_tracker.h"
Primiano Tucci919ca1e2019-08-21 20:26:58 +020033#include "test/gtest_and_gmock.h"
Primiano Tucci0d72a312018-08-07 14:42:45 +010034
Primiano Tucci355b8c82019-08-29 08:37:51 +020035#include "protos/perfetto/common/sys_stats_counters.pbzero.h"
36#include "protos/perfetto/trace/android/packages_list.pbzero.h"
37#include "protos/perfetto/trace/chrome/chrome_benchmark_metadata.pbzero.h"
38#include "protos/perfetto/trace/chrome/chrome_trace_event.pbzero.h"
Eric Seckler15ea5df2019-10-14 13:54:07 +010039#include "protos/perfetto/trace/clock_snapshot.pbzero.h"
Primiano Tucci355b8c82019-08-29 08:37:51 +020040#include "protos/perfetto/trace/ftrace/ftrace.pbzero.h"
41#include "protos/perfetto/trace/ftrace/ftrace_event.pbzero.h"
42#include "protos/perfetto/trace/ftrace/ftrace_event_bundle.pbzero.h"
43#include "protos/perfetto/trace/ftrace/generic.pbzero.h"
44#include "protos/perfetto/trace/ftrace/power.pbzero.h"
45#include "protos/perfetto/trace/ftrace/sched.pbzero.h"
46#include "protos/perfetto/trace/ftrace/task.pbzero.h"
47#include "protos/perfetto/trace/interned_data/interned_data.pbzero.h"
Oystein Eftevaag7f64c102019-08-29 10:27:31 -070048#include "protos/perfetto/trace/profiling/profile_packet.pbzero.h"
Primiano Tucci355b8c82019-08-29 08:37:51 +020049#include "protos/perfetto/trace/ps/process_tree.pbzero.h"
50#include "protos/perfetto/trace/sys_stats/sys_stats.pbzero.h"
51#include "protos/perfetto/trace/trace.pbzero.h"
52#include "protos/perfetto/trace/trace_packet.pbzero.h"
53#include "protos/perfetto/trace/track_event/debug_annotation.pbzero.h"
54#include "protos/perfetto/trace/track_event/task_execution.pbzero.h"
55#include "protos/perfetto/trace/track_event/thread_descriptor.pbzero.h"
Eric Secklerb32cacf2019-09-27 16:51:19 +010056#include "protos/perfetto/trace/track_event/track_descriptor.pbzero.h"
Primiano Tucci355b8c82019-08-29 08:37:51 +020057#include "protos/perfetto/trace/track_event/track_event.pbzero.h"
Lalit Maganti93b76362018-06-01 03:03:58 +010058
59namespace perfetto {
60namespace trace_processor {
61namespace {
62
Primiano Tucci2da5d2e2018-08-10 14:23:31 +010063using ::testing::_;
Lalit Maganti35622b72018-06-06 12:03:11 +010064using ::testing::Args;
Primiano Tucci711de1f2019-03-04 11:11:33 +000065using ::testing::AtLeast;
Lalit Maganti35622b72018-06-06 12:03:11 +010066using ::testing::ElementsAreArray;
67using ::testing::Eq;
Eric Seckler56a007d2019-05-02 16:25:14 +010068using ::testing::InSequence;
Ryan Savitski0476ee92019-07-09 14:29:33 +010069using ::testing::Invoke;
Eric Secklerd3b89d52019-07-10 15:36:29 +010070using ::testing::InvokeArgument;
Isabelle Taylor54ce7052018-10-01 14:00:15 +010071using ::testing::NiceMock;
Eric Seckler56a007d2019-05-02 16:25:14 +010072using ::testing::Pointwise;
73using ::testing::Return;
Ryan Savitski0476ee92019-07-09 14:29:33 +010074using ::testing::UnorderedElementsAreArray;
Lalit Maganti93b76362018-06-01 03:03:58 +010075
Primiano Tucci919ca1e2019-08-21 20:26:58 +020076MATCHER_P(DoubleEq, exp, "Double matcher that satisfies -Wfloat-equal") {
77 // The IEEE standard says that any comparison operation involving
78 // a NAN must return false.
Primiano Tuccid3c62b42019-08-22 07:07:59 +020079 double d_exp = exp;
80 double d_arg = arg;
81 if (isnan(d_exp) || isnan(d_arg))
Primiano Tucci919ca1e2019-08-21 20:26:58 +020082 return false;
Primiano Tuccid3c62b42019-08-22 07:07:59 +020083 return fabs(d_arg - d_exp) < 1e-128;
Primiano Tucci919ca1e2019-08-21 20:26:58 +020084}
85
Isabelle Taylora97c5f52018-10-23 17:36:12 +010086class MockEventTracker : public EventTracker {
Lalit Maganti35622b72018-06-06 12:03:11 +010087 public:
Isabelle Taylora97c5f52018-10-23 17:36:12 +010088 MockEventTracker(TraceProcessorContext* context) : EventTracker(context) {}
89 virtual ~MockEventTracker() = default;
Lalit Maganti35622b72018-06-06 12:03:11 +010090
Lalit Magantibeb73712019-02-08 11:28:09 +000091 MOCK_METHOD9(PushSchedSwitch,
Lalit Maganti35622b72018-06-06 12:03:11 +010092 void(uint32_t cpu,
Lalit Maganti85ca4a82018-12-07 17:28:02 +000093 int64_t timestamp,
Lalit Maganti35622b72018-06-06 12:03:11 +010094 uint32_t prev_pid,
Lalit Magantibeb73712019-02-08 11:28:09 +000095 base::StringView prev_comm,
96 int32_t prev_prio,
Lalit Maganti4af8dd82019-01-16 23:10:21 +000097 int64_t prev_state,
Lalit Magantifde29042018-10-04 13:28:52 +010098 uint32_t next_pid,
Lalit Maganti4af8dd82019-01-16 23:10:21 +000099 base::StringView next_comm,
Lalit Magantibeb73712019-02-08 11:28:09 +0000100 int32_t next_prio));
Isabelle Taylor15314ea2018-09-19 11:35:19 +0100101
Lalit Maganti521d97b2019-04-29 13:47:03 +0100102 MOCK_METHOD6(PushCounter,
Lalit Maganti85ca4a82018-12-07 17:28:02 +0000103 RowId(int64_t timestamp,
Lalit Maganti5ea9e932018-11-30 14:19:39 +0000104 double value,
105 StringId name_id,
Lalit Maganti85ca4a82018-12-07 17:28:02 +0000106 int64_t ref,
Lalit Maganti521d97b2019-04-29 13:47:03 +0100107 RefType ref_type,
108 bool resolve_utid_to_upid));
Eric Seckler651ca312019-06-05 16:41:51 +0100109
110 MOCK_METHOD6(PushInstant,
111 RowId(int64_t timestamp,
112 StringId name_id,
113 double value,
114 int64_t ref,
115 RefType ref_type,
116 bool resolve_utid_to_upid));
Isabelle Taylora0a22972018-08-03 12:06:12 +0100117};
118
119class MockProcessTracker : public ProcessTracker {
120 public:
121 MockProcessTracker(TraceProcessorContext* context)
122 : ProcessTracker(context) {}
123
Lalit Maganti161d1e62019-06-25 16:06:17 +0100124 MOCK_METHOD3(SetProcessMetadata,
Lalit Maganti08884242019-02-19 12:28:32 +0000125 UniquePid(uint32_t pid,
126 base::Optional<uint32_t> ppid,
127 base::StringView process_name));
Isabelle Taylora0a22972018-08-03 12:06:12 +0100128
Siddhartha Sd37e5662019-06-13 18:27:42 -0700129 MOCK_METHOD2(UpdateThreadName,
130 UniqueTid(uint32_t tid, StringId thread_name_id));
Isabelle Taylora0a22972018-08-03 12:06:12 +0100131 MOCK_METHOD2(UpdateThread, UniqueTid(uint32_t tid, uint32_t tgid));
Eric Secklera0366df2019-06-07 14:42:56 +0100132
133 MOCK_METHOD1(GetOrCreateProcess, UniquePid(uint32_t pid));
Lalit Maganti35622b72018-06-06 12:03:11 +0100134};
135
Ryan Savitski0476ee92019-07-09 14:29:33 +0100136// Mock trace storage that behaves like the real implementation, but allows for
137// the interactions with string interning/lookup to be overridden/inspected.
Isabelle Taylor14674d42018-09-07 11:33:11 +0100138class MockTraceStorage : public TraceStorage {
139 public:
Ryan Savitski0476ee92019-07-09 14:29:33 +0100140 MockTraceStorage() : TraceStorage() {
141 ON_CALL(*this, InternString(_))
142 .WillByDefault(Invoke([this](base::StringView str) {
143 return TraceStorage::InternString(str);
144 }));
145
146 ON_CALL(*this, GetString(_)).WillByDefault(Invoke([this](StringId id) {
147 return TraceStorage::GetString(id);
148 }));
Eric Secklerb32cacf2019-09-27 16:51:19 +0100149
150 ON_CALL(*this, GetThread(_))
151 .WillByDefault(Invoke(this, &MockTraceStorage::GetThreadImpl));
152 }
153
154 const Thread& GetThreadImpl(UniqueTid utid) {
155 return TraceStorage::GetThread(utid);
Ryan Savitski0476ee92019-07-09 14:29:33 +0100156 }
Isabelle Taylor14674d42018-09-07 11:33:11 +0100157
Isabelle Taylor15314ea2018-09-19 11:35:19 +0100158 MOCK_METHOD1(InternString, StringId(base::StringView));
Eric Secklerc93823e2019-06-03 16:49:19 +0100159 MOCK_CONST_METHOD1(GetString, NullTermStringView(StringId));
Eric Secklerb32cacf2019-09-27 16:51:19 +0100160
161 MOCK_CONST_METHOD1(GetThread, const Thread&(UniqueTid));
Isabelle Taylor14674d42018-09-07 11:33:11 +0100162};
163
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +0000164class MockArgsTracker : public ArgsTracker {
165 public:
166 MockArgsTracker(TraceProcessorContext* context) : ArgsTracker(context) {}
167
168 MOCK_METHOD4(AddArg,
169 void(RowId row_id, StringId flat_key, StringId key, Variadic));
170 MOCK_METHOD0(Flush, void());
171};
172
Eric Seckler56a007d2019-05-02 16:25:14 +0100173class MockSliceTracker : public SliceTracker {
174 public:
175 MockSliceTracker(TraceProcessorContext* context) : SliceTracker(context) {}
176
Lalit Maganti21b21632019-09-28 16:50:23 +0100177 MOCK_METHOD7(Begin,
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100178 base::Optional<uint32_t>(int64_t timestamp,
Lalit Maganti21b21632019-09-28 16:50:23 +0100179 TrackId track_id,
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100180 int64_t ref,
181 RefType ref_type,
182 StringId cat,
183 StringId name,
184 SetArgsCallback args_callback));
Lalit Maganti21b21632019-09-28 16:50:23 +0100185 MOCK_METHOD5(End,
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100186 base::Optional<uint32_t>(int64_t timestamp,
Lalit Maganti21b21632019-09-28 16:50:23 +0100187 TrackId track_id,
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100188 StringId cat,
189 StringId name,
190 SetArgsCallback args_callback));
Lalit Maganti21b21632019-09-28 16:50:23 +0100191 MOCK_METHOD8(Scoped,
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100192 base::Optional<uint32_t>(int64_t timestamp,
Lalit Maganti21b21632019-09-28 16:50:23 +0100193 TrackId track_id,
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100194 int64_t ref,
195 RefType ref_type,
196 StringId cat,
197 StringId name,
198 int64_t duration,
199 SetArgsCallback args_callback));
Eric Seckler56a007d2019-05-02 16:25:14 +0100200};
201
Primiano Tuccid933d912018-09-04 09:15:07 +0100202class ProtoTraceParserTest : public ::testing::Test {
203 public:
204 ProtoTraceParserTest() {
Ryan Savitski0476ee92019-07-09 14:29:33 +0100205 storage_ = new NiceMock<MockTraceStorage>();
206 context_.storage.reset(storage_);
Lalit Maganti4ea78d92019-09-20 20:20:41 +0100207 context_.track_tracker.reset(new TrackTracker(&context_));
Eric Secklerc93823e2019-06-03 16:49:19 +0100208 context_.args_tracker.reset(new ArgsTracker(&context_));
Isabelle Taylora97c5f52018-10-23 17:36:12 +0100209 event_ = new MockEventTracker(&context_);
210 context_.event_tracker.reset(event_);
Primiano Tuccid933d912018-09-04 09:15:07 +0100211 process_ = new MockProcessTracker(&context_);
212 context_.process_tracker.reset(process_);
Eric Seckler56a007d2019-05-02 16:25:14 +0100213 slice_ = new MockSliceTracker(&context_);
214 context_.slice_tracker.reset(slice_);
Eric Seckler15ea5df2019-10-14 13:54:07 +0100215 clock_ = new ClockTracker(&context_);
216 context_.clock_tracker.reset(clock_);
Primiano Tucci7de4ef22019-02-21 17:13:42 +0000217 context_.sorter.reset(new TraceSorter(&context_, 0 /*window size*/));
Deepanjan Roy01994ca2019-04-02 11:05:34 -0700218 context_.parser.reset(new ProtoTraceParser(&context_));
Primiano Tucci8e3da692019-06-08 08:56:01 +0100219 context_.systrace_parser.reset(new SystraceParser(&context_));
Oystein Eftevaag7f64c102019-08-29 10:27:31 -0700220 context_.stack_profile_tracker.reset(new StackProfileTracker(&context_));
Mohammad Reza Zakerinasabb06d1852019-09-11 14:41:36 -0400221 context_.vulkan_memory_tracker.reset(new VulkanMemoryTracker(&context_));
Primiano Tuccid933d912018-09-04 09:15:07 +0100222 }
Primiano Tucci7e330292018-08-24 19:10:52 +0200223
Primiano Tuccie5f11682019-03-22 07:21:49 +0000224 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
231 void SetUp() override { ResetTraceBuffers(); }
232
Primiano Tuccie5f11682019-03-22 07:21:49 +0000233 void 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());
Eric Seckler56a007d2019-05-02 16:25:14 +0100238 context_.chunk_reader.reset(new ProtoTraceTokenizer(&context_));
239 context_.chunk_reader->Parse(std::move(raw_trace), trace_bytes.size());
Primiano Tuccie5f11682019-03-22 07:21:49 +0000240
241 ResetTraceBuffers();
Primiano Tuccid933d912018-09-04 09:15:07 +0100242 }
243
Eric Secklerb7e26332019-07-19 12:46:17 +0100244 bool HasArg(ArgSetId set_id, StringId key_id, Variadic value) {
245 const auto& args = storage_->args();
246 auto rows =
247 std::equal_range(args.set_ids().begin(), args.set_ids().end(), set_id);
248 for (; rows.first != rows.second; rows.first++) {
249 size_t index = static_cast<size_t>(
250 std::distance(args.set_ids().begin(), rows.first));
251 if (args.keys()[index] == key_id) {
252 EXPECT_EQ(args.flat_keys()[index], key_id);
253 EXPECT_EQ(args.arg_values()[index], value);
254 if (args.flat_keys()[index] == key_id &&
255 args.arg_values()[index] == value) {
256 return true;
257 }
258 }
259 }
260 return false;
261 }
262
Primiano Tuccid933d912018-09-04 09:15:07 +0100263 protected:
Primiano Tuccie5f11682019-03-22 07:21:49 +0000264 std::unique_ptr<protozero::ScatteredHeapBuffer> heap_buf_;
265 std::unique_ptr<protozero::ScatteredStreamWriter> stream_writer_;
266 protos::pbzero::Trace trace_;
Primiano Tuccid933d912018-09-04 09:15:07 +0100267 TraceProcessorContext context_;
Isabelle Taylora97c5f52018-10-23 17:36:12 +0100268 MockEventTracker* event_;
Primiano Tuccid933d912018-09-04 09:15:07 +0100269 MockProcessTracker* process_;
Eric Seckler56a007d2019-05-02 16:25:14 +0100270 MockSliceTracker* slice_;
Eric Seckler15ea5df2019-10-14 13:54:07 +0100271 ClockTracker* clock_;
Ryan Savitski0476ee92019-07-09 14:29:33 +0100272 NiceMock<MockTraceStorage>* storage_;
Primiano Tuccid933d912018-09-04 09:15:07 +0100273};
274
275TEST_F(ProtoTraceParserTest, LoadSingleEvent) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000276 auto* bundle = trace_.add_packet()->set_ftrace_events();
Lalit Magantidf3e9262018-06-04 17:45:00 +0100277 bundle->set_cpu(10);
278
279 auto* event = bundle->add_event();
280 event->set_timestamp(1000);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000281 event->set_pid(12);
Lalit Magantidf3e9262018-06-04 17:45:00 +0100282
Lalit Magantibeb73712019-02-08 11:28:09 +0000283 static const char kProc1Name[] = "proc1";
284 static const char kProc2Name[] = "proc2";
Primiano Tuccie5f11682019-03-22 07:21:49 +0000285 auto* sched_switch = event->set_sched_switch();
Lalit Magantidf3e9262018-06-04 17:45:00 +0100286 sched_switch->set_prev_pid(10);
Lalit Magantibeb73712019-02-08 11:28:09 +0000287 sched_switch->set_prev_comm(kProc2Name);
288 sched_switch->set_prev_prio(256);
Lalit Maganti35622b72018-06-06 12:03:11 +0100289 sched_switch->set_prev_state(32);
Lalit Magantibeb73712019-02-08 11:28:09 +0000290 sched_switch->set_next_comm(kProc1Name);
Lalit Maganti35622b72018-06-06 12:03:11 +0100291 sched_switch->set_next_pid(100);
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000292 sched_switch->set_next_prio(1024);
Lalit Maganti35622b72018-06-06 12:03:11 +0100293
Lalit Magantibeb73712019-02-08 11:28:09 +0000294 EXPECT_CALL(*event_,
295 PushSchedSwitch(10, 1000, 10, base::StringView(kProc2Name), 256,
296 32, 100, base::StringView(kProc1Name), 1024));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000297 Tokenize();
Lalit Maganti93b76362018-06-01 03:03:58 +0100298}
299
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +0000300TEST_F(ProtoTraceParserTest, LoadEventsIntoRaw) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000301 auto* bundle = trace_.add_packet()->set_ftrace_events();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000302 bundle->set_cpu(10);
303
304 // This event is unknown and will only appear in
305 // raw events table.
306 auto* event = bundle->add_event();
307 event->set_timestamp(1000);
308 event->set_pid(12);
Primiano Tuccie5f11682019-03-22 07:21:49 +0000309 auto* task = event->set_task_newtask();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000310 task->set_pid(123);
311 static const char task_newtask[] = "task_newtask";
312 task->set_comm(task_newtask);
313 task->set_clone_flags(12);
314 task->set_oom_score_adj(15);
315
316 // This event has specific parsing logic, but will
317 // also appear in raw events table.
318 event = bundle->add_event();
319 event->set_timestamp(1001);
320 event->set_pid(12);
Primiano Tuccie5f11682019-03-22 07:21:49 +0000321 auto* print = event->set_print();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000322 print->set_ip(20);
323 static const char buf_value[] = "This is a print event";
324 print->set_buf(buf_value);
325
Primiano Tucci711de1f2019-03-04 11:11:33 +0000326 EXPECT_CALL(*storage_, InternString(base::StringView(task_newtask)))
327 .Times(AtLeast(1));
Lalit Maganti1d915a62019-01-07 12:10:42 +0000328 EXPECT_CALL(*storage_, InternString(base::StringView(buf_value)));
Primiano Tucci711de1f2019-03-04 11:11:33 +0000329 EXPECT_CALL(*process_, UpdateThread(123, 123));
Lalit Maganti1d915a62019-01-07 12:10:42 +0000330
Primiano Tuccie5f11682019-03-22 07:21:49 +0000331 Tokenize();
Ryan Savitski0476ee92019-07-09 14:29:33 +0100332
Lalit Maganti1d915a62019-01-07 12:10:42 +0000333 const auto& raw = context_.storage->raw_events();
Oystein Eftevaagbcd420a2019-05-31 15:40:07 -0700334 ASSERT_EQ(raw.raw_event_count(), 2u);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000335 const auto& args = context_.storage->args();
Oystein Eftevaagbcd420a2019-05-31 15:40:07 -0700336 ASSERT_EQ(args.args_count(), 6u);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000337 ASSERT_EQ(args.arg_values()[0].int_value, 123);
Ryan Savitski0476ee92019-07-09 14:29:33 +0100338 ASSERT_STREQ(
339 context_.storage->GetString(args.arg_values()[1].string_value).c_str(),
340 task_newtask);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000341 ASSERT_EQ(args.arg_values()[2].int_value, 12);
342 ASSERT_EQ(args.arg_values()[3].int_value, 15);
343 ASSERT_EQ(args.arg_values()[4].int_value, 20);
Ryan Savitski0476ee92019-07-09 14:29:33 +0100344 ASSERT_STREQ(
345 context_.storage->GetString(args.arg_values()[5].string_value).c_str(),
346 buf_value);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000347
348 // TODO(taylori): Add test ftrace event with all field types
349 // and test here.
350}
351
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +0000352TEST_F(ProtoTraceParserTest, LoadGenericFtrace) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000353 auto* packet = trace_.add_packet();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000354 packet->set_timestamp(100);
355
Primiano Tuccie5f11682019-03-22 07:21:49 +0000356 auto* bundle = packet->set_ftrace_events();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000357 bundle->set_cpu(4);
358
359 auto* ftrace = bundle->add_event();
360 ftrace->set_timestamp(100);
361 ftrace->set_pid(10);
362
Primiano Tuccie5f11682019-03-22 07:21:49 +0000363 auto* generic = ftrace->set_generic();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000364 generic->set_event_name("Test");
365
366 auto* field = generic->add_field();
367 field->set_name("meta1");
368 field->set_str_value("value1");
369
370 field = generic->add_field();
371 field->set_name("meta2");
372 field->set_int_value(-2);
373
374 field = generic->add_field();
375 field->set_name("meta3");
376 field->set_uint_value(3);
377
378 EXPECT_CALL(*storage_, InternString(base::StringView("Test")));
379 EXPECT_CALL(*storage_, InternString(base::StringView("meta1")));
380 EXPECT_CALL(*storage_, InternString(base::StringView("value1")));
381 EXPECT_CALL(*storage_, InternString(base::StringView("meta2")));
382 EXPECT_CALL(*storage_, InternString(base::StringView("meta3")));
383
Primiano Tuccie5f11682019-03-22 07:21:49 +0000384 Tokenize();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000385
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +0000386 const auto& raw = storage_->raw_events();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000387
Oystein Eftevaagbcd420a2019-05-31 15:40:07 -0700388 ASSERT_EQ(raw.raw_event_count(), 1u);
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +0000389 ASSERT_EQ(raw.timestamps().back(), 100);
Oystein Eftevaagbcd420a2019-05-31 15:40:07 -0700390 ASSERT_EQ(storage_->GetThread(raw.utids().back()).tid, 10u);
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +0000391
392 auto set_id = raw.arg_set_ids().back();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000393
Lalit Maganticc674222019-01-23 17:54:00 +0000394 const auto& args = storage_->args();
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +0000395 auto id_it =
396 std::equal_range(args.set_ids().begin(), args.set_ids().end(), set_id);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000397
398 // Ignore string calls as they are handled by checking InternString calls
399 // above.
400
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +0000401 auto it = id_it.first;
402 auto row = static_cast<size_t>(std::distance(args.set_ids().begin(), it));
403 ASSERT_EQ(args.arg_values()[++row].int_value, -2);
404 ASSERT_EQ(args.arg_values()[++row].int_value, 3);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000405}
406
Primiano Tuccid933d912018-09-04 09:15:07 +0100407TEST_F(ProtoTraceParserTest, LoadMultipleEvents) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000408 auto* bundle = trace_.add_packet()->set_ftrace_events();
Lalit Maganti35622b72018-06-06 12:03:11 +0100409 bundle->set_cpu(10);
410
411 auto* event = bundle->add_event();
412 event->set_timestamp(1000);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000413 event->set_pid(12);
Lalit Maganti35622b72018-06-06 12:03:11 +0100414
415 static const char kProcName1[] = "proc1";
Lalit Magantibeb73712019-02-08 11:28:09 +0000416 static const char kProcName2[] = "proc2";
Primiano Tuccie5f11682019-03-22 07:21:49 +0000417 auto* sched_switch = event->set_sched_switch();
Lalit Maganti35622b72018-06-06 12:03:11 +0100418 sched_switch->set_prev_pid(10);
Lalit Magantibeb73712019-02-08 11:28:09 +0000419 sched_switch->set_prev_comm(kProcName2);
420 sched_switch->set_prev_prio(256);
Lalit Maganti35622b72018-06-06 12:03:11 +0100421 sched_switch->set_prev_state(32);
Lalit Magantifde29042018-10-04 13:28:52 +0100422 sched_switch->set_next_comm(kProcName1);
Lalit Maganti35622b72018-06-06 12:03:11 +0100423 sched_switch->set_next_pid(100);
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000424 sched_switch->set_next_prio(1024);
Lalit Maganti35622b72018-06-06 12:03:11 +0100425
426 event = bundle->add_event();
427 event->set_timestamp(1001);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000428 event->set_pid(12);
Lalit Maganti35622b72018-06-06 12:03:11 +0100429
Primiano Tuccie5f11682019-03-22 07:21:49 +0000430 sched_switch = event->set_sched_switch();
Lalit Maganti35622b72018-06-06 12:03:11 +0100431 sched_switch->set_prev_pid(100);
Lalit Magantibeb73712019-02-08 11:28:09 +0000432 sched_switch->set_prev_comm(kProcName1);
433 sched_switch->set_prev_prio(256);
Lalit Maganti35622b72018-06-06 12:03:11 +0100434 sched_switch->set_prev_state(32);
Lalit Magantifde29042018-10-04 13:28:52 +0100435 sched_switch->set_next_comm(kProcName2);
Lalit Maganti35622b72018-06-06 12:03:11 +0100436 sched_switch->set_next_pid(10);
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000437 sched_switch->set_next_prio(512);
Lalit Maganti35622b72018-06-06 12:03:11 +0100438
Lalit Magantibeb73712019-02-08 11:28:09 +0000439 EXPECT_CALL(*event_,
440 PushSchedSwitch(10, 1000, 10, base::StringView(kProcName2), 256,
441 32, 100, base::StringView(kProcName1), 1024));
Lalit Maganti35622b72018-06-06 12:03:11 +0100442
Lalit Magantibeb73712019-02-08 11:28:09 +0000443 EXPECT_CALL(*event_,
444 PushSchedSwitch(10, 1001, 100, base::StringView(kProcName1), 256,
445 32, 10, base::StringView(kProcName2), 512));
Lalit Maganti35622b72018-06-06 12:03:11 +0100446
Primiano Tuccie5f11682019-03-22 07:21:49 +0000447 Tokenize();
Lalit Maganti35622b72018-06-06 12:03:11 +0100448}
449
Primiano Tuccid933d912018-09-04 09:15:07 +0100450TEST_F(ProtoTraceParserTest, LoadMultiplePackets) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000451 auto* bundle = trace_.add_packet()->set_ftrace_events();
Lalit Maganti35622b72018-06-06 12:03:11 +0100452 bundle->set_cpu(10);
453
454 auto* event = bundle->add_event();
455 event->set_timestamp(1000);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000456 event->set_pid(12);
Lalit Maganti35622b72018-06-06 12:03:11 +0100457
458 static const char kProcName1[] = "proc1";
Lalit Magantibeb73712019-02-08 11:28:09 +0000459 static const char kProcName2[] = "proc2";
Primiano Tuccie5f11682019-03-22 07:21:49 +0000460 auto* sched_switch = event->set_sched_switch();
Lalit Maganti35622b72018-06-06 12:03:11 +0100461 sched_switch->set_prev_pid(10);
Lalit Magantibeb73712019-02-08 11:28:09 +0000462 sched_switch->set_prev_comm(kProcName2);
463 sched_switch->set_prev_prio(256);
Lalit Maganti35622b72018-06-06 12:03:11 +0100464 sched_switch->set_prev_state(32);
Lalit Magantifde29042018-10-04 13:28:52 +0100465 sched_switch->set_next_comm(kProcName1);
Lalit Maganti35622b72018-06-06 12:03:11 +0100466 sched_switch->set_next_pid(100);
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000467 sched_switch->set_next_prio(1024);
Lalit Maganti35622b72018-06-06 12:03:11 +0100468
Primiano Tuccie5f11682019-03-22 07:21:49 +0000469 bundle = trace_.add_packet()->set_ftrace_events();
Lalit Maganti35622b72018-06-06 12:03:11 +0100470 bundle->set_cpu(10);
471
472 event = bundle->add_event();
473 event->set_timestamp(1001);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000474 event->set_pid(12);
Lalit Maganti35622b72018-06-06 12:03:11 +0100475
Primiano Tuccie5f11682019-03-22 07:21:49 +0000476 sched_switch = event->set_sched_switch();
Lalit Maganti35622b72018-06-06 12:03:11 +0100477 sched_switch->set_prev_pid(100);
Lalit Magantibeb73712019-02-08 11:28:09 +0000478 sched_switch->set_prev_comm(kProcName1);
479 sched_switch->set_prev_prio(256);
Lalit Maganti35622b72018-06-06 12:03:11 +0100480 sched_switch->set_prev_state(32);
Lalit Magantifde29042018-10-04 13:28:52 +0100481 sched_switch->set_next_comm(kProcName2);
Lalit Maganti35622b72018-06-06 12:03:11 +0100482 sched_switch->set_next_pid(10);
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000483 sched_switch->set_next_prio(512);
Lalit Maganti35622b72018-06-06 12:03:11 +0100484
Lalit Magantibeb73712019-02-08 11:28:09 +0000485 EXPECT_CALL(*event_,
486 PushSchedSwitch(10, 1000, 10, base::StringView(kProcName2), 256,
487 32, 100, base::StringView(kProcName1), 1024));
Lalit Maganti35622b72018-06-06 12:03:11 +0100488
Lalit Magantibeb73712019-02-08 11:28:09 +0000489 EXPECT_CALL(*event_,
490 PushSchedSwitch(10, 1001, 100, base::StringView(kProcName1), 256,
491 32, 10, base::StringView(kProcName2), 512));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000492 Tokenize();
Lalit Maganti93b76362018-06-01 03:03:58 +0100493}
494
Primiano Tuccid933d912018-09-04 09:15:07 +0100495TEST_F(ProtoTraceParserTest, RepeatedLoadSinglePacket) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000496 auto* bundle = trace_.add_packet()->set_ftrace_events();
Primiano Tuccid933d912018-09-04 09:15:07 +0100497 bundle->set_cpu(10);
498 auto* event = bundle->add_event();
499 event->set_timestamp(1000);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000500 event->set_pid(12);
Primiano Tuccid933d912018-09-04 09:15:07 +0100501 static const char kProcName1[] = "proc1";
Lalit Magantibeb73712019-02-08 11:28:09 +0000502 static const char kProcName2[] = "proc2";
Primiano Tuccie5f11682019-03-22 07:21:49 +0000503 auto* sched_switch = event->set_sched_switch();
Primiano Tuccid933d912018-09-04 09:15:07 +0100504 sched_switch->set_prev_pid(10);
Lalit Magantibeb73712019-02-08 11:28:09 +0000505 sched_switch->set_prev_comm(kProcName2);
506 sched_switch->set_prev_prio(256);
Primiano Tuccid933d912018-09-04 09:15:07 +0100507 sched_switch->set_prev_state(32);
Lalit Magantifde29042018-10-04 13:28:52 +0100508 sched_switch->set_next_comm(kProcName1);
Primiano Tuccid933d912018-09-04 09:15:07 +0100509 sched_switch->set_next_pid(100);
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000510 sched_switch->set_next_prio(1024);
Primiano Tuccie5f11682019-03-22 07:21:49 +0000511 EXPECT_CALL(*event_,
512 PushSchedSwitch(10, 1000, 10, base::StringView(kProcName2), 256,
513 32, 100, base::StringView(kProcName1), 1024));
514 Tokenize();
Lalit Maganti35622b72018-06-06 12:03:11 +0100515
Primiano Tuccie5f11682019-03-22 07:21:49 +0000516 bundle = trace_.add_packet()->set_ftrace_events();
Primiano Tuccid933d912018-09-04 09:15:07 +0100517 bundle->set_cpu(10);
518 event = bundle->add_event();
519 event->set_timestamp(1001);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000520 event->set_pid(12);
Primiano Tuccie5f11682019-03-22 07:21:49 +0000521 sched_switch = event->set_sched_switch();
Primiano Tuccid933d912018-09-04 09:15:07 +0100522 sched_switch->set_prev_pid(100);
Lalit Magantibeb73712019-02-08 11:28:09 +0000523 sched_switch->set_prev_comm(kProcName1);
524 sched_switch->set_prev_prio(256);
Primiano Tuccid933d912018-09-04 09:15:07 +0100525 sched_switch->set_prev_state(32);
Lalit Magantifde29042018-10-04 13:28:52 +0100526 sched_switch->set_next_comm(kProcName2);
Primiano Tuccid933d912018-09-04 09:15:07 +0100527 sched_switch->set_next_pid(10);
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000528 sched_switch->set_next_prio(512);
Primiano Tuccid933d912018-09-04 09:15:07 +0100529
Lalit Magantibeb73712019-02-08 11:28:09 +0000530 EXPECT_CALL(*event_,
531 PushSchedSwitch(10, 1001, 100, base::StringView(kProcName1), 256,
532 32, 10, base::StringView(kProcName2), 512));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000533 Tokenize();
Lalit Maganti93b76362018-06-01 03:03:58 +0100534}
535
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100536TEST_F(ProtoTraceParserTest, LoadMemInfo) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000537 auto* packet = trace_.add_packet();
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100538 uint64_t ts = 1000;
539 packet->set_timestamp(ts);
Primiano Tuccie5f11682019-03-22 07:21:49 +0000540 auto* bundle = packet->set_sys_stats();
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100541 auto* meminfo = bundle->add_meminfo();
Primiano Tuccie5f11682019-03-22 07:21:49 +0000542 meminfo->set_key(protos::pbzero::MEMINFO_MEM_TOTAL);
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100543 uint32_t value = 10;
544 meminfo->set_value(value);
545
Primiano Tucci919ca1e2019-08-21 20:26:58 +0200546 EXPECT_CALL(*event_,
547 PushCounter(static_cast<int64_t>(ts), DoubleEq(value * 1024.0), _,
548 0, RefType::kRefNoRef, false));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000549 Tokenize();
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100550}
551
552TEST_F(ProtoTraceParserTest, LoadVmStats) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000553 auto* packet = trace_.add_packet();
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100554 uint64_t ts = 1000;
555 packet->set_timestamp(ts);
Primiano Tuccie5f11682019-03-22 07:21:49 +0000556 auto* bundle = packet->set_sys_stats();
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100557 auto* meminfo = bundle->add_vmstat();
Primiano Tuccie5f11682019-03-22 07:21:49 +0000558 meminfo->set_key(protos::pbzero::VMSTAT_COMPACT_SUCCESS);
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100559 uint32_t value = 10;
560 meminfo->set_value(value);
561
Primiano Tucci919ca1e2019-08-21 20:26:58 +0200562 EXPECT_CALL(*event_, PushCounter(static_cast<int64_t>(ts), DoubleEq(value), _,
563 0, RefType::kRefNoRef, false));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000564 Tokenize();
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100565}
566
Isabelle Taylor14674d42018-09-07 11:33:11 +0100567TEST_F(ProtoTraceParserTest, LoadCpuFreq) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000568 auto* bundle = trace_.add_packet()->set_ftrace_events();
Isabelle Taylor14674d42018-09-07 11:33:11 +0100569 bundle->set_cpu(12);
570 auto* event = bundle->add_event();
571 event->set_timestamp(1000);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000572 event->set_pid(12);
Primiano Tuccie5f11682019-03-22 07:21:49 +0000573 auto* cpu_freq = event->set_cpu_frequency();
Isabelle Taylor14674d42018-09-07 11:33:11 +0100574 cpu_freq->set_cpu_id(10);
575 cpu_freq->set_state(2000);
576
Primiano Tucci919ca1e2019-08-21 20:26:58 +0200577 EXPECT_CALL(*event_, PushCounter(1000, DoubleEq(2000), _, 10,
578 RefType::kRefCpuId, false));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000579 Tokenize();
Isabelle Taylor14674d42018-09-07 11:33:11 +0100580}
581
Primiano Tuccid933d912018-09-04 09:15:07 +0100582TEST_F(ProtoTraceParserTest, LoadProcessPacket) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000583 auto* tree = trace_.add_packet()->set_process_tree();
Isabelle Taylord80932a2018-06-19 17:00:47 +0100584 auto* process = tree->add_processes();
585 static const char kProcName1[] = "proc1";
586
587 process->add_cmdline(kProcName1);
588 process->set_pid(1);
Lalit Magantib4274aa2019-07-09 14:29:48 +0100589 process->set_ppid(3);
Isabelle Taylord80932a2018-06-19 17:00:47 +0100590
Lalit Maganti08884242019-02-19 12:28:32 +0000591 EXPECT_CALL(*process_,
Lalit Magantib4274aa2019-07-09 14:29:48 +0100592 SetProcessMetadata(1, Eq(3u), base::StringView(kProcName1)));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000593 Tokenize();
Isabelle Taylord80932a2018-06-19 17:00:47 +0100594}
595
Primiano Tuccid933d912018-09-04 09:15:07 +0100596TEST_F(ProtoTraceParserTest, LoadProcessPacket_FirstCmdline) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000597 auto* tree = trace_.add_packet()->set_process_tree();
Isabelle Taylord80932a2018-06-19 17:00:47 +0100598 auto* process = tree->add_processes();
599 static const char kProcName1[] = "proc1";
600 static const char kProcName2[] = "proc2";
601
602 process->add_cmdline(kProcName1);
603 process->add_cmdline(kProcName2);
604 process->set_pid(1);
Lalit Magantib4274aa2019-07-09 14:29:48 +0100605 process->set_ppid(3);
Isabelle Taylord80932a2018-06-19 17:00:47 +0100606
Lalit Maganti08884242019-02-19 12:28:32 +0000607 EXPECT_CALL(*process_,
Lalit Magantib4274aa2019-07-09 14:29:48 +0100608 SetProcessMetadata(1, Eq(3u), base::StringView(kProcName1)));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000609 Tokenize();
Isabelle Taylord80932a2018-06-19 17:00:47 +0100610}
611
Primiano Tuccid933d912018-09-04 09:15:07 +0100612TEST_F(ProtoTraceParserTest, LoadThreadPacket) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000613 auto* tree = trace_.add_packet()->set_process_tree();
Isabelle Taylor3dd366c2018-06-22 16:21:41 +0100614 auto* thread = tree->add_threads();
615 thread->set_tid(1);
616 thread->set_tgid(2);
617
Primiano Tuccid933d912018-09-04 09:15:07 +0100618 EXPECT_CALL(*process_, UpdateThread(1, 2));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000619 Tokenize();
Isabelle Taylor3dd366c2018-06-22 16:21:41 +0100620}
621
Siddhartha Sd37e5662019-06-13 18:27:42 -0700622TEST_F(ProtoTraceParserTest, ThreadNameFromThreadDescriptor) {
Siddhartha Sd37e5662019-06-13 18:27:42 -0700623 context_.sorter.reset(new TraceSorter(
624 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
625 {
626 auto* packet = trace_.add_packet();
627 packet->set_trusted_packet_sequence_id(1);
628 packet->set_incremental_state_cleared(true);
629 auto* thread_desc = packet->set_thread_descriptor();
630 thread_desc->set_pid(15);
631 thread_desc->set_tid(16);
632 thread_desc->set_reference_timestamp_us(1000);
633 thread_desc->set_reference_thread_time_us(2000);
634 thread_desc->set_thread_name("OldThreadName");
635 }
636 {
637 auto* packet = trace_.add_packet();
638 packet->set_trusted_packet_sequence_id(1);
639 packet->set_incremental_state_cleared(true);
640 auto* thread_desc = packet->set_thread_descriptor();
641 thread_desc->set_pid(15);
642 thread_desc->set_tid(16);
643 thread_desc->set_reference_timestamp_us(1000);
644 thread_desc->set_reference_thread_time_us(2000);
645 thread_desc->set_thread_name("NewThreadName");
646 }
647 {
648 auto* packet = trace_.add_packet();
649 packet->set_trusted_packet_sequence_id(2);
650 packet->set_incremental_state_cleared(true);
651 auto* thread_desc = packet->set_thread_descriptor();
652 thread_desc->set_pid(15);
653 thread_desc->set_tid(11);
654 thread_desc->set_reference_timestamp_us(1000);
655 thread_desc->set_reference_thread_time_us(2000);
656 thread_desc->set_thread_name("DifferentThreadName");
657 }
658
659 InSequence in_sequence; // Below slices should be sorted by timestamp.
660
661 EXPECT_CALL(*storage_, InternString(base::StringView("OldThreadName")))
662 .WillOnce(Return(1));
Lalit Maganti1a2936f2019-08-29 17:42:33 +0100663 EXPECT_CALL(*process_, UpdateThreadName(16, StringId(1)));
Siddhartha Sd37e5662019-06-13 18:27:42 -0700664 // Packet with same thread, but different name should update the name.
665 EXPECT_CALL(*storage_, InternString(base::StringView("NewThreadName")))
666 .WillOnce(Return(2));
Lalit Maganti1a2936f2019-08-29 17:42:33 +0100667 EXPECT_CALL(*process_, UpdateThreadName(16, StringId(2)));
Siddhartha Sd37e5662019-06-13 18:27:42 -0700668 EXPECT_CALL(*storage_, InternString(base::StringView("DifferentThreadName")))
669 .WillOnce(Return(3));
Lalit Maganti1a2936f2019-08-29 17:42:33 +0100670 EXPECT_CALL(*process_, UpdateThreadName(11, StringId(3)));
Siddhartha Sd37e5662019-06-13 18:27:42 -0700671
672 Tokenize();
673 context_.sorter->ExtractEventsForced();
674}
675
Eric Seckler56a007d2019-05-02 16:25:14 +0100676TEST_F(ProtoTraceParserTest, TrackEventWithoutInternedData) {
Eric Seckler56a007d2019-05-02 16:25:14 +0100677 context_.sorter.reset(new TraceSorter(
678 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
679
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 }
690 {
691 auto* packet = trace_.add_packet();
692 packet->set_trusted_packet_sequence_id(1);
693 auto* event = packet->set_track_event();
694 event->set_timestamp_delta_us(10); // absolute: 1010.
695 event->set_thread_time_delta_us(5); // absolute: 2005.
696 event->add_category_iids(1);
697 auto* legacy_event = event->set_legacy_event();
698 legacy_event->set_name_iid(1);
699 legacy_event->set_phase('B');
700 }
701 {
702 auto* packet = trace_.add_packet();
703 packet->set_trusted_packet_sequence_id(1);
704 auto* event = packet->set_track_event();
705 event->set_timestamp_delta_us(10); // absolute: 1020.
706 event->set_thread_time_delta_us(5); // absolute: 2010.
707 event->add_category_iids(1);
708 auto* legacy_event = event->set_legacy_event();
709 legacy_event->set_name_iid(1);
710 legacy_event->set_phase('E');
711 }
712 {
713 auto* packet = trace_.add_packet();
714 packet->set_trusted_packet_sequence_id(1);
715 auto* event = packet->set_track_event();
716 event->set_timestamp_absolute_us(1005);
717 event->set_thread_time_absolute_us(2003);
718 event->add_category_iids(2);
719 event->add_category_iids(3);
720 auto* legacy_event = event->set_legacy_event();
721 legacy_event->set_name_iid(2);
722 legacy_event->set_phase('X');
723 legacy_event->set_duration_us(23); // absolute end: 1028.
724 legacy_event->set_thread_duration_us(12); // absolute end: 2015.
725 }
726
727 Tokenize();
728
729 EXPECT_CALL(*process_, UpdateThread(16, 15))
730 .Times(3)
731 .WillRepeatedly(Return(1));
732
Eric Secklerb32cacf2019-09-27 16:51:19 +0100733 TraceStorage::Thread thread(16);
734 thread.upid = 1u;
735 EXPECT_CALL(*storage_, GetThread(1))
736 .Times(3)
737 .WillRepeatedly(testing::ReturnRef(thread));
738
Eric Secklerd3b89d52019-07-10 15:36:29 +0100739 MockArgsTracker args(&context_);
740
Lalit Maganti21b21632019-09-28 16:50:23 +0100741 constexpr TrackId track = 0u;
Eric Seckler56a007d2019-05-02 16:25:14 +0100742 InSequence in_sequence; // Below slices should be sorted by timestamp.
Lalit Maganti21b21632019-09-28 16:50:23 +0100743 EXPECT_CALL(*slice_, Scoped(1005000, track, 1, RefType::kRefUtid,
744 kNullStringId, kNullStringId, 23000, _))
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100745 .WillOnce(DoAll(
Lalit Maganti21b21632019-09-28 16:50:23 +0100746 InvokeArgument<7>(
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100747 &args, TraceStorage::CreateRowId(TableId::kNestableSlices, 0u)),
748 Return(0u)));
Lalit Maganti21b21632019-09-28 16:50:23 +0100749 EXPECT_CALL(*slice_, Begin(1010000, track, 1, RefType::kRefUtid,
750 kNullStringId, kNullStringId, _))
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100751 .WillOnce(DoAll(
Lalit Maganti21b21632019-09-28 16:50:23 +0100752 InvokeArgument<6>(
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100753 &args, TraceStorage::CreateRowId(TableId::kNestableSlices, 1u)),
754 Return(1u)));
Lalit Maganti21b21632019-09-28 16:50:23 +0100755 EXPECT_CALL(*slice_, End(1020000, track, kNullStringId, kNullStringId, _))
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100756 .WillOnce(DoAll(
Lalit Maganti21b21632019-09-28 16:50:23 +0100757 InvokeArgument<4>(
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100758 &args, TraceStorage::CreateRowId(TableId::kNestableSlices, 1u)),
759 Return(1u)));
Eric Seckler56a007d2019-05-02 16:25:14 +0100760
761 context_.sorter->ExtractEventsForced();
Eric Secklerd3b89d52019-07-10 15:36:29 +0100762
763 EXPECT_EQ(storage_->thread_slices().slice_count(), 2u);
764 EXPECT_EQ(storage_->thread_slices().slice_ids()[0], 0u);
765 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[0], 2003000);
766 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[0], 12000);
767 EXPECT_EQ(storage_->thread_slices().slice_ids()[1], 1u);
768 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[1], 2005000);
769 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[1], 5000);
Eric Seckler56a007d2019-05-02 16:25:14 +0100770}
771
Eric Seckler58fcbf12019-08-07 15:05:43 +0100772TEST_F(ProtoTraceParserTest, TrackEventWithoutInternedDataWithTypes) {
773 context_.sorter.reset(new TraceSorter(
774 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
775
776 {
777 auto* packet = trace_.add_packet();
778 packet->set_trusted_packet_sequence_id(1);
779 packet->set_incremental_state_cleared(true);
780 auto* thread_desc = packet->set_thread_descriptor();
781 thread_desc->set_pid(15);
782 thread_desc->set_tid(16);
783 thread_desc->set_reference_timestamp_us(1000);
784 thread_desc->set_reference_thread_time_us(2000);
785 }
786 {
787 auto* packet = trace_.add_packet();
788 packet->set_trusted_packet_sequence_id(1);
789 auto* event = packet->set_track_event();
790 event->set_timestamp_delta_us(10); // absolute: 1010.
791 event->set_thread_time_delta_us(5); // absolute: 2005.
792 event->add_category_iids(1);
793 event->set_type(protos::pbzero::TrackEvent::TYPE_SLICE_BEGIN);
794 auto* legacy_event = event->set_legacy_event();
795 legacy_event->set_name_iid(1);
796 }
797 {
798 auto* packet = trace_.add_packet();
799 packet->set_trusted_packet_sequence_id(1);
800 auto* event = packet->set_track_event();
801 event->set_timestamp_delta_us(10); // absolute: 1020.
802 event->set_thread_time_delta_us(5); // absolute: 2010.
803 event->add_category_iids(1);
804 event->set_type(protos::pbzero::TrackEvent::TYPE_SLICE_END);
805 auto* legacy_event = event->set_legacy_event();
806 legacy_event->set_name_iid(1);
807 }
Eric Seckler361c10e2019-08-13 11:40:13 +0100808 {
809 auto* packet = trace_.add_packet();
810 packet->set_trusted_packet_sequence_id(1);
811 auto* event = packet->set_track_event();
812 event->set_timestamp_absolute_us(1015);
813 event->set_thread_time_absolute_us(2007);
814 event->add_category_iids(2);
815 event->set_type(protos::pbzero::TrackEvent::TYPE_INSTANT);
816 auto* legacy_event = event->set_legacy_event();
817 legacy_event->set_name_iid(2);
818 }
Eric Seckler58fcbf12019-08-07 15:05:43 +0100819
820 Tokenize();
821
822 EXPECT_CALL(*process_, UpdateThread(16, 15))
Eric Seckler361c10e2019-08-13 11:40:13 +0100823 .Times(3)
Eric Seckler58fcbf12019-08-07 15:05:43 +0100824 .WillRepeatedly(Return(1));
825
Eric Secklerb32cacf2019-09-27 16:51:19 +0100826 TraceStorage::Thread thread(16);
827 thread.upid = 1u;
828 EXPECT_CALL(*storage_, GetThread(1))
829 .Times(3)
830 .WillRepeatedly(testing::ReturnRef(thread));
831
Eric Seckler58fcbf12019-08-07 15:05:43 +0100832 MockArgsTracker args(&context_);
833
Lalit Maganti21b21632019-09-28 16:50:23 +0100834 constexpr TrackId track = 0u;
Eric Seckler58fcbf12019-08-07 15:05:43 +0100835 InSequence in_sequence; // Below slices should be sorted by timestamp.
Lalit Maganti21b21632019-09-28 16:50:23 +0100836 EXPECT_CALL(*slice_, Begin(1010000, track, 1, RefType::kRefUtid,
837 kNullStringId, kNullStringId, _))
Eric Seckler361c10e2019-08-13 11:40:13 +0100838 .WillOnce(DoAll(
839 InvokeArgument<6>(
Lalit Maganti21b21632019-09-28 16:50:23 +0100840 &args, TraceStorage::CreateRowId(TableId::kNestableSlices, 0u)),
841 Return(0u)));
842 EXPECT_CALL(*slice_, Scoped(1015000, track, 1, RefType::kRefUtid,
843 kNullStringId, kNullStringId, 0, _))
844 .WillOnce(DoAll(
845 InvokeArgument<7>(
Eric Seckler361c10e2019-08-13 11:40:13 +0100846 &args, TraceStorage::CreateRowId(TableId::kNestableSlices, 1u)),
847 Return(1u)));
Lalit Maganti21b21632019-09-28 16:50:23 +0100848 EXPECT_CALL(*slice_, End(1020000, track, kNullStringId, kNullStringId, _))
Eric Seckler58fcbf12019-08-07 15:05:43 +0100849 .WillOnce(DoAll(
Lalit Maganti21b21632019-09-28 16:50:23 +0100850 InvokeArgument<4>(
Eric Seckler58fcbf12019-08-07 15:05:43 +0100851 &args, TraceStorage::CreateRowId(TableId::kNestableSlices, 0u)),
852 Return(0u)));
853
854 context_.sorter->ExtractEventsForced();
855
Eric Seckler361c10e2019-08-13 11:40:13 +0100856 EXPECT_EQ(storage_->thread_slices().slice_count(), 2u);
Eric Seckler58fcbf12019-08-07 15:05:43 +0100857 EXPECT_EQ(storage_->thread_slices().slice_ids()[0], 0u);
858 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[0], 2005000);
859 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[0], 5000);
Eric Seckler361c10e2019-08-13 11:40:13 +0100860 EXPECT_EQ(storage_->thread_slices().slice_ids()[1], 1u);
861 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[1], 2007000);
862 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[1], 0);
Eric Seckler58fcbf12019-08-07 15:05:43 +0100863}
864
Eric Seckler56a007d2019-05-02 16:25:14 +0100865TEST_F(ProtoTraceParserTest, TrackEventWithInternedData) {
Eric Seckler56a007d2019-05-02 16:25:14 +0100866 context_.sorter.reset(new TraceSorter(
867 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
868
869 {
870 auto* packet = trace_.add_packet();
871 packet->set_trusted_packet_sequence_id(1);
872 packet->set_incremental_state_cleared(true);
873 auto* thread_desc = packet->set_thread_descriptor();
874 thread_desc->set_pid(15);
875 thread_desc->set_tid(16);
876 thread_desc->set_reference_timestamp_us(1000);
877 thread_desc->set_reference_thread_time_us(2000);
Eric Seckler54f30a32019-07-19 15:10:29 +0100878 thread_desc->set_reference_thread_instruction_count(3000);
Eric Seckler56a007d2019-05-02 16:25:14 +0100879 }
880 {
881 auto* packet = trace_.add_packet();
882 packet->set_trusted_packet_sequence_id(1);
883 auto* event = packet->set_track_event();
Eric Seckler54f30a32019-07-19 15:10:29 +0100884 event->set_timestamp_delta_us(10); // absolute: 1010.
885 event->set_thread_time_delta_us(5); // absolute: 2005.
886 event->set_thread_instruction_count_delta(20); // absolute: 3020.
Eric Seckler56a007d2019-05-02 16:25:14 +0100887 event->add_category_iids(1);
888 auto* legacy_event = event->set_legacy_event();
889 legacy_event->set_name_iid(1);
890 legacy_event->set_phase('B');
891
892 auto* interned_data = packet->set_interned_data();
893 auto cat1 = interned_data->add_event_categories();
894 cat1->set_iid(1);
895 cat1->set_name("cat1");
Eric Seckler0c460ef2019-08-14 15:42:36 +0100896 auto ev1 = interned_data->add_event_names();
Eric Seckler56a007d2019-05-02 16:25:14 +0100897 ev1->set_iid(1);
898 ev1->set_name("ev1");
899 }
900 {
901 auto* packet = trace_.add_packet();
902 packet->set_trusted_packet_sequence_id(1);
903 auto* event = packet->set_track_event();
Eric Seckler651ca312019-06-05 16:41:51 +0100904 event->set_timestamp_absolute_us(1040);
905 event->set_thread_time_absolute_us(2030);
Eric Seckler54f30a32019-07-19 15:10:29 +0100906 event->set_thread_instruction_count_absolute(3100);
Eric Seckler651ca312019-06-05 16:41:51 +0100907 event->add_category_iids(1);
908 auto* legacy_event = event->set_legacy_event();
909 legacy_event->set_name_iid(1);
910 legacy_event->set_phase('I');
911 }
912 {
913 auto* packet = trace_.add_packet();
914 packet->set_trusted_packet_sequence_id(1);
915 auto* event = packet->set_track_event();
Eric Secklera0366df2019-06-07 14:42:56 +0100916 event->set_timestamp_absolute_us(1050);
917 event->add_category_iids(1);
918 auto* legacy_event = event->set_legacy_event();
919 legacy_event->set_name_iid(1);
920 legacy_event->set_phase('i');
921 legacy_event->set_instant_event_scope(
922 protos::pbzero::TrackEvent::LegacyEvent::SCOPE_PROCESS);
923 }
924 {
925 auto* packet = trace_.add_packet();
926 packet->set_trusted_packet_sequence_id(1);
927 auto* event = packet->set_track_event();
Eric Seckler54f30a32019-07-19 15:10:29 +0100928 event->set_timestamp_delta_us(10); // absolute: 1020.
929 event->set_thread_time_delta_us(5); // absolute: 2010.
930 event->set_thread_instruction_count_delta(20); // absolute: 3040.
Eric Seckler56a007d2019-05-02 16:25:14 +0100931 event->add_category_iids(1);
932 auto* legacy_event = event->set_legacy_event();
933 legacy_event->set_name_iid(1);
934 legacy_event->set_phase('E');
935 }
936 {
937 auto* packet = trace_.add_packet();
938 packet->set_trusted_packet_sequence_id(1);
939 auto* event = packet->set_track_event();
940 event->set_timestamp_absolute_us(1005);
941 event->set_thread_time_absolute_us(2003);
Eric Seckler54f30a32019-07-19 15:10:29 +0100942 event->set_thread_instruction_count_absolute(3010);
Eric Seckler56a007d2019-05-02 16:25:14 +0100943 event->add_category_iids(2);
944 event->add_category_iids(3);
945 auto* legacy_event = event->set_legacy_event();
946 legacy_event->set_name_iid(2);
947 legacy_event->set_phase('X');
Eric Seckler54f30a32019-07-19 15:10:29 +0100948 legacy_event->set_duration_us(23); // absolute end: 1028.
949 legacy_event->set_thread_duration_us(12); // absolute end: 2015.
950 legacy_event->set_thread_instruction_delta(50); // absolute end: 3060.
Eric Seckler56a007d2019-05-02 16:25:14 +0100951
952 auto* interned_data = packet->set_interned_data();
953 auto cat2 = interned_data->add_event_categories();
954 cat2->set_iid(2);
955 cat2->set_name("cat2");
956 auto cat3 = interned_data->add_event_categories();
957 cat3->set_iid(3);
958 cat3->set_name("cat3");
Eric Seckler0c460ef2019-08-14 15:42:36 +0100959 auto ev2 = interned_data->add_event_names();
Eric Seckler56a007d2019-05-02 16:25:14 +0100960 ev2->set_iid(2);
961 ev2->set_name("ev2");
962 }
963
964 Tokenize();
965
966 EXPECT_CALL(*process_, UpdateThread(16, 15))
Eric Secklera0366df2019-06-07 14:42:56 +0100967 .Times(5)
Eric Seckler56a007d2019-05-02 16:25:14 +0100968 .WillRepeatedly(Return(1));
969
Eric Secklerb32cacf2019-09-27 16:51:19 +0100970 TraceStorage::Thread thread(16);
971 thread.upid = 2u;
972 EXPECT_CALL(*storage_, GetThread(1))
973 .Times(5)
974 .WillRepeatedly(testing::ReturnRef(thread));
Eric Secklera0366df2019-06-07 14:42:56 +0100975
Eric Secklerd3b89d52019-07-10 15:36:29 +0100976 MockArgsTracker args(&context_);
977
Lalit Maganti21b21632019-09-28 16:50:23 +0100978 constexpr TrackId thread_1_track = 0u;
979 constexpr TrackId process_2_track = 1u;
980
Eric Seckler56a007d2019-05-02 16:25:14 +0100981 InSequence in_sequence; // Below slices should be sorted by timestamp.
982
983 EXPECT_CALL(*storage_, InternString(base::StringView("cat2,cat3")))
984 .WillOnce(Return(1));
985 EXPECT_CALL(*storage_, InternString(base::StringView("ev2")))
986 .WillOnce(Return(2));
Lalit Maganti21b21632019-09-28 16:50:23 +0100987 EXPECT_CALL(*slice_, Scoped(1005000, thread_1_track, 1, RefType::kRefUtid,
988 StringId(1), StringId(2), 23000, _))
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100989 .WillOnce(DoAll(
Lalit Maganti21b21632019-09-28 16:50:23 +0100990 InvokeArgument<7>(
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100991 &args, TraceStorage::CreateRowId(TableId::kNestableSlices, 0u)),
992 Return(0u)));
Eric Seckler56a007d2019-05-02 16:25:14 +0100993
994 EXPECT_CALL(*storage_, InternString(base::StringView("cat1")))
995 .WillOnce(Return(3));
996 EXPECT_CALL(*storage_, InternString(base::StringView("ev1")))
997 .WillOnce(Return(4));
Lalit Maganti21b21632019-09-28 16:50:23 +0100998 EXPECT_CALL(*slice_, Begin(1010000, thread_1_track, 1, RefType::kRefUtid,
999 StringId(3), StringId(4), _))
Lalit Maganti81a02cd2019-07-12 17:05:11 +01001000 .WillOnce(DoAll(
1001 InvokeArgument<6>(
Lalit Maganti21b21632019-09-28 16:50:23 +01001002 &args, TraceStorage::CreateRowId(TableId::kNestableSlices, 1u)),
1003 Return(1u)));
1004
1005 EXPECT_CALL(*slice_,
1006 End(1020000, thread_1_track, StringId(3), StringId(4), _))
1007 .WillOnce(DoAll(
1008 InvokeArgument<4>(
1009 &args, TraceStorage::CreateRowId(TableId::kNestableSlices, 1u)),
1010 Return(1u)));
1011
1012 EXPECT_CALL(*slice_, Scoped(1040000, thread_1_track, 1, RefType::kRefUtid,
1013 StringId(3), StringId(4), 0, _))
1014 .WillOnce(DoAll(
1015 InvokeArgument<7>(
Lalit Maganti81a02cd2019-07-12 17:05:11 +01001016 &args, TraceStorage::CreateRowId(TableId::kNestableSlices, 2u)),
1017 Return(2u)));
Eric Secklera0366df2019-06-07 14:42:56 +01001018
Lalit Maganti21b21632019-09-28 16:50:23 +01001019 EXPECT_CALL(*slice_, Scoped(1050000, process_2_track, 2, RefType::kRefUpid,
1020 StringId(3), StringId(4), 0, _))
Lalit Maganti81a02cd2019-07-12 17:05:11 +01001021 .WillOnce(DoAll(
Lalit Maganti21b21632019-09-28 16:50:23 +01001022 InvokeArgument<7>(
Lalit Maganti81a02cd2019-07-12 17:05:11 +01001023 &args, TraceStorage::CreateRowId(TableId::kNestableSlices, 3u)),
1024 Return(3u)));
Eric Seckler87fd11a2019-06-07 15:52:28 +01001025
1026 context_.sorter->ExtractEventsForced();
Eric Secklerd3b89d52019-07-10 15:36:29 +01001027
1028 EXPECT_EQ(storage_->thread_slices().slice_count(), 3u);
1029 EXPECT_EQ(storage_->thread_slices().slice_ids()[0], 0u);
1030 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[0], 2003000);
1031 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[0], 12000);
Eric Seckler54f30a32019-07-19 15:10:29 +01001032 EXPECT_EQ(storage_->thread_slices().thread_instruction_counts()[0], 3010);
1033 EXPECT_EQ(storage_->thread_slices().thread_instruction_deltas()[0], 50);
Eric Secklerd3b89d52019-07-10 15:36:29 +01001034 EXPECT_EQ(storage_->thread_slices().slice_ids()[1], 1u);
1035 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[1], 2005000);
1036 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[1], 5000);
Eric Seckler54f30a32019-07-19 15:10:29 +01001037 EXPECT_EQ(storage_->thread_slices().thread_instruction_counts()[1], 3020);
1038 EXPECT_EQ(storage_->thread_slices().thread_instruction_deltas()[1], 20);
Eric Secklerd3b89d52019-07-10 15:36:29 +01001039 EXPECT_EQ(storage_->thread_slices().slice_ids()[2], 2u);
1040 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[2], 2030000);
1041 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[2], 0);
Eric Seckler54f30a32019-07-19 15:10:29 +01001042 EXPECT_EQ(storage_->thread_slices().thread_instruction_counts()[2], 3100);
1043 EXPECT_EQ(storage_->thread_slices().thread_instruction_deltas()[2], 0);
Eric Seckler87fd11a2019-06-07 15:52:28 +01001044}
1045
1046TEST_F(ProtoTraceParserTest, TrackEventAsyncEvents) {
Eric Seckler87fd11a2019-06-07 15:52:28 +01001047 context_.sorter.reset(new TraceSorter(
1048 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
1049
1050 {
1051 auto* packet = trace_.add_packet();
1052 packet->set_trusted_packet_sequence_id(1);
1053 packet->set_incremental_state_cleared(true);
1054 auto* thread_desc = packet->set_thread_descriptor();
1055 thread_desc->set_pid(15);
1056 thread_desc->set_tid(16);
1057 thread_desc->set_reference_timestamp_us(1000);
1058 thread_desc->set_reference_thread_time_us(2000);
Eric Seckler54f30a32019-07-19 15:10:29 +01001059 thread_desc->set_reference_thread_instruction_count(3000);
Eric Seckler87fd11a2019-06-07 15:52:28 +01001060 }
1061 {
1062 auto* packet = trace_.add_packet();
1063 packet->set_trusted_packet_sequence_id(1);
1064 auto* event = packet->set_track_event();
Eric Seckler54f30a32019-07-19 15:10:29 +01001065 event->set_timestamp_delta_us(10); // absolute: 1010.
1066 event->set_thread_time_delta_us(5); // absolute: 2005.
1067 event->set_thread_instruction_count_delta(20); // absolute: 3020.
Eric Seckler87fd11a2019-06-07 15:52:28 +01001068 event->add_category_iids(1);
1069 auto* legacy_event = event->set_legacy_event();
1070 legacy_event->set_name_iid(1);
1071 legacy_event->set_phase('b');
1072 legacy_event->set_global_id(10);
Eric Secklerc3430c62019-07-22 10:49:58 +01001073 legacy_event->set_use_async_tts(true);
Eric Seckler87fd11a2019-06-07 15:52:28 +01001074
1075 auto* interned_data = packet->set_interned_data();
1076 auto cat1 = interned_data->add_event_categories();
1077 cat1->set_iid(1);
1078 cat1->set_name("cat1");
Eric Seckler0c460ef2019-08-14 15:42:36 +01001079 auto ev1 = interned_data->add_event_names();
Eric Seckler87fd11a2019-06-07 15:52:28 +01001080 ev1->set_iid(1);
1081 ev1->set_name("ev1");
1082 }
1083 {
1084 auto* packet = trace_.add_packet();
1085 packet->set_trusted_packet_sequence_id(1);
1086 auto* event = packet->set_track_event();
Eric Seckler54f30a32019-07-19 15:10:29 +01001087 event->set_timestamp_delta_us(10); // absolute: 1020.
1088 event->set_thread_time_delta_us(5); // absolute: 2010.
1089 event->set_thread_instruction_count_delta(20); // absolute: 3040.
Eric Seckler87fd11a2019-06-07 15:52:28 +01001090 event->add_category_iids(1);
1091 auto* legacy_event = event->set_legacy_event();
1092 legacy_event->set_name_iid(1);
1093 legacy_event->set_phase('e');
1094 legacy_event->set_global_id(10);
Eric Secklerc3430c62019-07-22 10:49:58 +01001095 legacy_event->set_use_async_tts(true);
Eric Seckler87fd11a2019-06-07 15:52:28 +01001096 }
1097 {
1098 auto* packet = trace_.add_packet();
1099 packet->set_trusted_packet_sequence_id(1);
1100 auto* event = packet->set_track_event();
1101 event->set_timestamp_absolute_us(1015);
1102 event->add_category_iids(2);
1103 auto* legacy_event = event->set_legacy_event();
1104 legacy_event->set_name_iid(2);
1105 legacy_event->set_phase('n');
1106 legacy_event->set_global_id(10);
1107
1108 auto* interned_data = packet->set_interned_data();
1109 auto cat2 = interned_data->add_event_categories();
1110 cat2->set_iid(2);
1111 cat2->set_name("cat2");
Eric Seckler0c460ef2019-08-14 15:42:36 +01001112 auto ev2 = interned_data->add_event_names();
Eric Seckler87fd11a2019-06-07 15:52:28 +01001113 ev2->set_iid(2);
1114 ev2->set_name("ev2");
1115 }
1116 {
1117 auto* packet = trace_.add_packet();
1118 packet->set_trusted_packet_sequence_id(1);
1119 auto* event = packet->set_track_event();
1120 event->set_timestamp_absolute_us(1030);
1121 event->add_category_iids(2);
1122 auto* legacy_event = event->set_legacy_event();
1123 legacy_event->set_name_iid(2);
1124 legacy_event->set_phase('n');
1125 legacy_event->set_local_id(15);
1126 legacy_event->set_id_scope("scope1");
1127 }
1128
1129 Tokenize();
1130
1131 EXPECT_CALL(*process_, UpdateThread(16, 15))
1132 .Times(4)
1133 .WillRepeatedly(Return(1));
Eric Secklerb32cacf2019-09-27 16:51:19 +01001134
1135 TraceStorage::Thread thread(16);
1136 thread.upid = 1u;
1137 EXPECT_CALL(*storage_, GetThread(1))
1138 .Times(4)
1139 .WillRepeatedly(testing::ReturnRef(thread));
Eric Seckler87fd11a2019-06-07 15:52:28 +01001140
1141 InSequence in_sequence; // Below slices should be sorted by timestamp.
1142
1143 EXPECT_CALL(*storage_, InternString(base::StringView("cat1")))
1144 .WillOnce(Return(1));
1145 EXPECT_CALL(*storage_, InternString(base::StringView("ev1")))
1146 .WillOnce(Return(2));
Lalit Maganti21b21632019-09-28 16:50:23 +01001147 EXPECT_CALL(*slice_, Begin(1010000, 1, 1, RefType::kRefTrack, StringId(1),
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001148 StringId(2), _))
Eric Secklerc3430c62019-07-22 10:49:58 +01001149 .WillOnce(Return(0u));
Eric Seckler87fd11a2019-06-07 15:52:28 +01001150
1151 EXPECT_CALL(*storage_, InternString(base::StringView("cat2")))
1152 .WillOnce(Return(3));
1153 EXPECT_CALL(*storage_, InternString(base::StringView("ev2")))
1154 .WillOnce(Return(4));
Lalit Maganti21b21632019-09-28 16:50:23 +01001155 EXPECT_CALL(*slice_, Scoped(1015000, 1, 1, RefType::kRefTrack, StringId(3),
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001156 StringId(4), 0, _));
Eric Seckler87fd11a2019-06-07 15:52:28 +01001157
Lalit Maganti21b21632019-09-28 16:50:23 +01001158 EXPECT_CALL(*slice_, End(1020000, 1, StringId(1), StringId(2), _))
Eric Secklerc3430c62019-07-22 10:49:58 +01001159 .WillOnce(Return(0u));
Eric Seckler87fd11a2019-06-07 15:52:28 +01001160
1161 EXPECT_CALL(*storage_, InternString(base::StringView("scope1")))
1162 .WillOnce(Return(5));
Lalit Maganti21b21632019-09-28 16:50:23 +01001163 EXPECT_CALL(*slice_, Scoped(1030000, 2, 2, RefType::kRefTrack, StringId(3),
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001164 StringId(4), 0, _));
Eric Seckler651ca312019-06-05 16:41:51 +01001165
Eric Seckler56a007d2019-05-02 16:25:14 +01001166 context_.sorter->ExtractEventsForced();
Eric Seckler5703ede2019-07-10 10:13:02 +01001167
Eric Secklerb32cacf2019-09-27 16:51:19 +01001168 // First track is for the thread; second and third are the async event tracks.
1169 EXPECT_EQ(storage_->track_table().size(), 3u);
1170 EXPECT_EQ(storage_->track_table().name()[1], 2u);
1171 EXPECT_EQ(storage_->track_table().name()[2], 4u);
Lalit Maganti53bdbb22019-09-25 11:11:18 +01001172
1173 EXPECT_EQ(storage_->process_track_table().size(), 1u);
1174 EXPECT_EQ(storage_->process_track_table().upid()[0], 1u);
Eric Secklerc3430c62019-07-22 10:49:58 +01001175
1176 EXPECT_EQ(storage_->virtual_track_slices().slice_count(), 1u);
1177 EXPECT_EQ(storage_->virtual_track_slices().slice_ids()[0], 0u);
1178 EXPECT_EQ(storage_->virtual_track_slices().thread_timestamp_ns()[0], 2005000);
1179 EXPECT_EQ(storage_->virtual_track_slices().thread_duration_ns()[0], 5000);
Eric Seckler54f30a32019-07-19 15:10:29 +01001180 EXPECT_EQ(storage_->virtual_track_slices().thread_instruction_counts()[0],
1181 3020);
1182 EXPECT_EQ(storage_->virtual_track_slices().thread_instruction_deltas()[0],
1183 20);
Eric Seckler56a007d2019-05-02 16:25:14 +01001184}
1185
Eric Secklerb32cacf2019-09-27 16:51:19 +01001186// TODO(eseckler): Also test instant events on separate tracks.
1187TEST_F(ProtoTraceParserTest, TrackEventWithTrackDescriptors) {
1188 context_.sorter.reset(new TraceSorter(
1189 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
1190
1191 // Sequence 1.
1192 {
1193 auto* packet = trace_.add_packet();
1194 packet->set_trusted_packet_sequence_id(1);
1195 packet->set_incremental_state_cleared(true);
1196 auto* track_desc = packet->set_track_descriptor();
1197 track_desc->set_uuid(1234);
1198 track_desc->set_name("Thread track 1");
1199 auto* thread_desc = track_desc->set_thread();
1200 thread_desc->set_pid(15);
1201 thread_desc->set_tid(16);
1202 }
1203 {
1204 auto* packet = trace_.add_packet();
1205 packet->set_trusted_packet_sequence_id(1);
1206 auto* track_desc = packet->set_track_descriptor();
1207 track_desc->set_uuid(5678);
1208 track_desc->set_name("Async track 1");
1209 }
1210 {
1211 // Async event started on "Async track 1".
1212 auto* packet = trace_.add_packet();
1213 packet->set_trusted_packet_sequence_id(1);
1214 packet->set_timestamp(1010000);
1215 auto* event = packet->set_track_event();
1216 event->set_track_uuid(5678);
1217 event->set_thread_time_absolute_us(2005);
1218 event->set_thread_instruction_count_absolute(3020);
1219 event->add_category_iids(1);
1220 event->set_name_iid(1);
1221 event->set_type(protos::pbzero::TrackEvent::TYPE_SLICE_BEGIN);
1222 auto* legacy_event = event->set_legacy_event();
1223 legacy_event->set_use_async_tts(true);
1224
1225 auto* interned_data = packet->set_interned_data();
1226 auto cat1 = interned_data->add_event_categories();
1227 cat1->set_iid(1);
1228 cat1->set_name("cat1");
1229 auto ev1 = interned_data->add_event_names();
1230 ev1->set_iid(1);
1231 ev1->set_name("ev1");
1232 }
1233 {
1234 // Instant event on "Thread track 1".
1235 auto* packet = trace_.add_packet();
1236 packet->set_trusted_packet_sequence_id(1);
1237 packet->set_timestamp(1015000);
1238 auto* event = packet->set_track_event();
1239 event->set_track_uuid(1234);
1240 event->set_thread_time_absolute_us(2007);
1241 event->add_category_iids(2);
1242 event->set_name_iid(2);
1243 event->set_type(protos::pbzero::TrackEvent::TYPE_INSTANT);
1244
1245 auto* interned_data = packet->set_interned_data();
1246 auto cat1 = interned_data->add_event_categories();
1247 cat1->set_iid(2);
1248 cat1->set_name("cat2");
1249 auto ev1 = interned_data->add_event_names();
1250 ev1->set_iid(2);
1251 ev1->set_name("ev2");
1252 }
1253
1254 // Sequence 2.
1255 {
1256 auto* packet = trace_.add_packet();
1257 packet->set_trusted_packet_sequence_id(2);
1258 packet->set_incremental_state_cleared(true);
1259 auto* track_desc = packet->set_track_descriptor();
1260 track_desc->set_uuid(4321);
1261 track_desc->set_name("Thread track 2");
1262 auto* thread_desc = track_desc->set_thread();
1263 thread_desc->set_pid(15);
1264 thread_desc->set_tid(17);
1265 }
1266 {
1267 auto* packet = trace_.add_packet();
1268 packet->set_trusted_packet_sequence_id(2);
1269 auto* track_desc = packet->set_track_descriptor();
1270 track_desc->set_uuid(5678); // "Async track 1" defined on sequence 1.
1271 }
1272 {
1273 // Async event completed on "Async track 1".
1274 auto* packet = trace_.add_packet();
1275 packet->set_trusted_packet_sequence_id(2);
1276 packet->set_timestamp(1020000);
1277 auto* event = packet->set_track_event();
1278 event->set_track_uuid(5678);
1279 event->set_thread_time_absolute_us(2010);
1280 event->set_thread_instruction_count_absolute(3040);
1281 event->set_type(protos::pbzero::TrackEvent::TYPE_SLICE_END);
1282 auto* legacy_event = event->set_legacy_event();
1283 legacy_event->set_use_async_tts(true);
1284 }
1285 {
1286 // Instant event on "Thread track 2".
1287 auto* packet = trace_.add_packet();
1288 packet->set_trusted_packet_sequence_id(2);
1289 packet->set_timestamp(1016000);
1290 auto* event = packet->set_track_event();
1291 event->set_track_uuid(4321);
1292 event->set_thread_time_absolute_us(2008);
1293 event->add_category_iids(1);
1294 event->set_name_iid(1);
1295 event->set_type(protos::pbzero::TrackEvent::TYPE_INSTANT);
1296
1297 auto* interned_data = packet->set_interned_data();
1298 auto cat1 = interned_data->add_event_categories();
1299 cat1->set_iid(1);
1300 cat1->set_name("cat3");
1301 auto ev1 = interned_data->add_event_names();
1302 ev1->set_iid(1);
1303 ev1->set_name("ev3");
1304 }
1305
1306 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillRepeatedly(Return(1));
1307 EXPECT_CALL(*process_, UpdateThread(17, 15)).WillRepeatedly(Return(2));
1308
1309 TraceStorage::Thread thread1(16);
1310 thread1.upid = 1u;
1311 EXPECT_CALL(*storage_, GetThread(1))
1312 .WillRepeatedly(testing::ReturnRef(thread1));
1313 TraceStorage::Thread thread2(16);
1314 thread2.upid = 2u;
1315 EXPECT_CALL(*storage_, GetThread(2))
1316 .WillRepeatedly(testing::ReturnRef(thread2));
1317
1318 EXPECT_CALL(*storage_, InternString(base::StringView("Thread track 1")))
1319 .WillOnce(Return(10));
1320 EXPECT_CALL(*storage_, InternString(base::StringView("Async track 1")))
1321 .WillOnce(Return(11));
1322 EXPECT_CALL(*storage_, InternString(base::StringView("Thread track 2")))
1323 .WillOnce(Return(12));
1324 EXPECT_CALL(*storage_, InternString(base::StringView("")))
1325 .WillOnce(Return(0));
1326
1327 Tokenize();
1328
1329 // First track is "Thread track 1"; second is "Async track 1", third is
1330 // "Thread track 2".
1331 EXPECT_EQ(storage_->track_table().size(), 3u);
1332 EXPECT_EQ(storage_->track_table().name()[0], 10u); // "Thread track 1"
1333 EXPECT_EQ(storage_->track_table().name()[1], 11u); // "Async track 1"
1334 EXPECT_EQ(storage_->track_table().name()[2], 12u); // "Thread track 2"
1335 EXPECT_EQ(storage_->thread_track_table().size(), 2u);
1336 EXPECT_EQ(storage_->thread_track_table().utid()[0], 1u);
1337 EXPECT_EQ(storage_->thread_track_table().utid()[1], 2u);
1338
1339 InSequence in_sequence; // Below slices should be sorted by timestamp.
1340
1341 EXPECT_CALL(*storage_, InternString(base::StringView("cat1")))
1342 .WillOnce(Return(1));
1343 EXPECT_CALL(*storage_, InternString(base::StringView("ev1")))
1344 .WillOnce(Return(2));
Lalit Maganti21b21632019-09-28 16:50:23 +01001345 EXPECT_CALL(*slice_, Begin(1010000, 1, 1, RefType::kRefTrack, StringId(1),
Eric Secklerb32cacf2019-09-27 16:51:19 +01001346 StringId(2), _))
1347 .WillOnce(Return(0u));
1348
1349 EXPECT_CALL(*storage_, InternString(base::StringView("cat2")))
1350 .WillOnce(Return(3));
1351 EXPECT_CALL(*storage_, InternString(base::StringView("ev2")))
1352 .WillOnce(Return(4));
Lalit Maganti21b21632019-09-28 16:50:23 +01001353 EXPECT_CALL(*slice_, Scoped(1015000, 0, 1, RefType::kRefUtid, StringId(3),
Eric Secklerb32cacf2019-09-27 16:51:19 +01001354 StringId(4), 0, _))
1355 .WillOnce(Return(1u));
1356
1357 EXPECT_CALL(*storage_, InternString(base::StringView("cat3")))
1358 .WillOnce(Return(5));
1359 EXPECT_CALL(*storage_, InternString(base::StringView("ev3")))
1360 .WillOnce(Return(6));
Lalit Maganti21b21632019-09-28 16:50:23 +01001361 EXPECT_CALL(*slice_, Scoped(1016000, 2, 2, RefType::kRefUtid, StringId(5),
Eric Secklerb32cacf2019-09-27 16:51:19 +01001362 StringId(6), 0, _))
1363 .WillOnce(Return(2u));
1364
Lalit Maganti21b21632019-09-28 16:50:23 +01001365 EXPECT_CALL(*slice_, End(1020000, 1, StringId(0), StringId(0), _))
Eric Secklerb32cacf2019-09-27 16:51:19 +01001366 .WillOnce(Return(0u));
1367
1368 context_.sorter->ExtractEventsForced();
1369
1370 // Track tables shouldn't have changed.
1371 EXPECT_EQ(storage_->track_table().size(), 3u);
1372 EXPECT_EQ(storage_->thread_track_table().size(), 2u);
1373
1374 EXPECT_EQ(storage_->virtual_track_slices().slice_count(), 1u);
1375 EXPECT_EQ(storage_->virtual_track_slices().slice_ids()[0], 0u);
1376 EXPECT_EQ(storage_->virtual_track_slices().thread_timestamp_ns()[0], 2005000);
1377 EXPECT_EQ(storage_->virtual_track_slices().thread_duration_ns()[0], 5000);
1378 EXPECT_EQ(storage_->virtual_track_slices().thread_instruction_counts()[0],
1379 3020);
1380 EXPECT_EQ(storage_->virtual_track_slices().thread_instruction_deltas()[0],
1381 20);
1382
1383 EXPECT_EQ(storage_->thread_slices().slice_count(), 2u);
1384 EXPECT_EQ(storage_->thread_slices().slice_ids()[0], 1u);
1385 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[0], 2007000);
1386 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[0], 0);
1387 EXPECT_EQ(storage_->thread_slices().thread_instruction_counts()[0], 0);
1388 EXPECT_EQ(storage_->thread_slices().thread_instruction_deltas()[0], 0);
1389 EXPECT_EQ(storage_->thread_slices().slice_ids()[1], 2u);
1390 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[1], 2008000);
1391 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[1], 0);
1392 EXPECT_EQ(storage_->thread_slices().thread_instruction_counts()[1], 0);
1393 EXPECT_EQ(storage_->thread_slices().thread_instruction_deltas()[1], 0);
1394}
1395
Eric Seckler56a007d2019-05-02 16:25:14 +01001396TEST_F(ProtoTraceParserTest, TrackEventWithoutIncrementalStateReset) {
Eric Seckler56a007d2019-05-02 16:25:14 +01001397 context_.sorter.reset(new TraceSorter(
1398 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
1399
1400 {
1401 auto* packet = trace_.add_packet();
1402 packet->set_trusted_packet_sequence_id(1);
1403 auto* thread_desc = packet->set_thread_descriptor();
1404 thread_desc->set_pid(15);
1405 thread_desc->set_tid(16);
1406 thread_desc->set_reference_timestamp_us(1000);
1407 thread_desc->set_reference_thread_time_us(2000);
1408 }
1409 {
1410 // Event should be discarded because incremental state was never cleared.
1411 auto* packet = trace_.add_packet();
1412 packet->set_trusted_packet_sequence_id(1);
1413 auto* event = packet->set_track_event();
1414 event->set_timestamp_delta_us(10); // absolute: 1010.
1415 event->set_thread_time_delta_us(5); // absolute: 2005.
1416 event->add_category_iids(1);
1417 auto* legacy_event = event->set_legacy_event();
1418 legacy_event->set_name_iid(1);
1419 legacy_event->set_phase('B');
1420 }
1421
1422 Tokenize();
1423
Lalit Maganti21b21632019-09-28 16:50:23 +01001424 EXPECT_CALL(*slice_, Begin(_, _, _, _, _, _, _)).Times(0);
Eric Seckler56a007d2019-05-02 16:25:14 +01001425 context_.sorter->ExtractEventsForced();
1426}
1427
1428TEST_F(ProtoTraceParserTest, TrackEventWithoutThreadDescriptor) {
Eric Seckler56a007d2019-05-02 16:25:14 +01001429 context_.sorter.reset(new TraceSorter(
1430 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
1431
1432 {
1433 // Event should be discarded because no thread descriptor was seen yet.
1434 auto* packet = trace_.add_packet();
1435 packet->set_trusted_packet_sequence_id(1);
1436 packet->set_incremental_state_cleared(true);
1437 auto* event = packet->set_track_event();
1438 event->set_timestamp_delta_us(10);
1439 event->set_thread_time_delta_us(5);
1440 event->add_category_iids(1);
1441 auto* legacy_event = event->set_legacy_event();
1442 legacy_event->set_name_iid(1);
1443 legacy_event->set_phase('B');
1444 }
1445
1446 Tokenize();
1447
Lalit Maganti21b21632019-09-28 16:50:23 +01001448 EXPECT_CALL(*slice_, Begin(_, _, _, _, _, _, _)).Times(0);
Eric Seckler56a007d2019-05-02 16:25:14 +01001449 context_.sorter->ExtractEventsForced();
1450}
1451
1452TEST_F(ProtoTraceParserTest, TrackEventWithDataLoss) {
Eric Seckler56a007d2019-05-02 16:25:14 +01001453 context_.sorter.reset(new TraceSorter(
1454 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
1455
1456 {
1457 auto* packet = trace_.add_packet();
1458 packet->set_trusted_packet_sequence_id(1);
1459 packet->set_incremental_state_cleared(true);
1460 auto* thread_desc = packet->set_thread_descriptor();
1461 thread_desc->set_pid(15);
1462 thread_desc->set_tid(16);
1463 thread_desc->set_reference_timestamp_us(1000);
1464 thread_desc->set_reference_thread_time_us(2000);
1465 }
1466 {
1467 auto* packet = trace_.add_packet();
1468 packet->set_trusted_packet_sequence_id(1);
1469 auto* event = packet->set_track_event();
1470 event->set_timestamp_delta_us(10); // absolute: 1010.
1471 event->set_thread_time_delta_us(5); // absolute: 2005.
1472 event->add_category_iids(1);
1473 auto* legacy_event = event->set_legacy_event();
1474 legacy_event->set_name_iid(1);
1475 legacy_event->set_phase('B');
1476 }
1477 {
1478 // Event should be dropped because data loss occurred before.
1479 auto* packet = trace_.add_packet();
1480 packet->set_trusted_packet_sequence_id(1);
1481 packet->set_previous_packet_dropped(true); // Data loss occurred.
1482 auto* event = packet->set_track_event();
1483 event->set_timestamp_delta_us(10);
1484 event->set_thread_time_delta_us(5);
1485 event->add_category_iids(1);
1486 auto* legacy_event = event->set_legacy_event();
1487 legacy_event->set_name_iid(1);
1488 legacy_event->set_phase('E');
1489 }
1490 {
1491 // Event should be dropped because incremental state is invalid.
1492 auto* packet = trace_.add_packet();
1493 packet->set_trusted_packet_sequence_id(1);
1494 auto* event = packet->set_track_event();
1495 event->set_timestamp_delta_us(10);
1496 event->set_thread_time_delta_us(5);
1497 event->add_category_iids(1);
1498 auto* legacy_event = event->set_legacy_event();
1499 legacy_event->set_name_iid(1);
1500 legacy_event->set_phase('E');
1501 }
1502 {
1503 // Event should be dropped because no new thread descriptor was seen yet.
1504 auto* packet = trace_.add_packet();
1505 packet->set_trusted_packet_sequence_id(1);
1506 packet->set_incremental_state_cleared(true);
1507 auto* event = packet->set_track_event();
1508 event->set_timestamp_delta_us(10);
1509 event->set_thread_time_delta_us(5);
1510 event->add_category_iids(1);
1511 auto* legacy_event = event->set_legacy_event();
1512 legacy_event->set_name_iid(1);
1513 legacy_event->set_phase('E');
1514 }
1515 {
1516 auto* packet = trace_.add_packet();
1517 packet->set_trusted_packet_sequence_id(1);
1518 auto* thread_desc = packet->set_thread_descriptor();
1519 thread_desc->set_pid(15);
1520 thread_desc->set_tid(16);
1521 thread_desc->set_reference_timestamp_us(2000);
1522 thread_desc->set_reference_thread_time_us(3000);
1523 }
1524 {
1525 auto* packet = trace_.add_packet();
1526 packet->set_trusted_packet_sequence_id(1);
1527 auto* event = packet->set_track_event();
1528 event->set_timestamp_delta_us(10); // absolute: 2010.
1529 event->set_thread_time_delta_us(5); // absolute: 3005.
1530 event->add_category_iids(1);
1531 auto* legacy_event = event->set_legacy_event();
1532 legacy_event->set_name_iid(1);
1533 legacy_event->set_phase('E');
1534 }
1535
1536 Tokenize();
1537
1538 EXPECT_CALL(*process_, UpdateThread(16, 15))
1539 .Times(2)
1540 .WillRepeatedly(Return(1));
1541
Eric Secklerb32cacf2019-09-27 16:51:19 +01001542 TraceStorage::Thread thread(16);
1543 thread.upid = 1u;
1544 EXPECT_CALL(*storage_, GetThread(1))
1545 .Times(2)
1546 .WillRepeatedly(testing::ReturnRef(thread));
1547
Lalit Maganti21b21632019-09-28 16:50:23 +01001548 constexpr TrackId track = 0u;
Eric Seckler56a007d2019-05-02 16:25:14 +01001549 InSequence in_sequence; // Below slices should be sorted by timestamp.
Lalit Maganti21b21632019-09-28 16:50:23 +01001550 EXPECT_CALL(*slice_, Begin(1010000, track, 1, RefType::kRefUtid,
1551 kNullStringId, kNullStringId, _));
1552 EXPECT_CALL(*slice_, End(2010000, track, kNullStringId, kNullStringId, _));
Eric Seckler56a007d2019-05-02 16:25:14 +01001553
1554 context_.sorter->ExtractEventsForced();
1555}
1556
1557TEST_F(ProtoTraceParserTest, TrackEventMultipleSequences) {
Eric Seckler56a007d2019-05-02 16:25:14 +01001558 context_.sorter.reset(new TraceSorter(
1559 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
1560
1561 {
1562 auto* packet = trace_.add_packet();
1563 packet->set_trusted_packet_sequence_id(1);
1564 packet->set_incremental_state_cleared(true);
1565 auto* thread_desc = packet->set_thread_descriptor();
1566 thread_desc->set_pid(15);
1567 thread_desc->set_tid(16);
1568 thread_desc->set_reference_timestamp_us(1000);
1569 thread_desc->set_reference_thread_time_us(2000);
1570 }
1571 {
1572 auto* packet = trace_.add_packet();
1573 packet->set_trusted_packet_sequence_id(1);
1574 auto* event = packet->set_track_event();
1575 event->set_timestamp_delta_us(10); // absolute: 1010.
1576 event->set_thread_time_delta_us(5); // absolute: 2005.
1577 event->add_category_iids(1);
1578 auto* legacy_event = event->set_legacy_event();
1579 legacy_event->set_name_iid(1);
1580 legacy_event->set_phase('B');
1581
1582 auto* interned_data = packet->set_interned_data();
1583 auto cat1 = interned_data->add_event_categories();
1584 cat1->set_iid(1);
1585 cat1->set_name("cat1");
Eric Seckler0c460ef2019-08-14 15:42:36 +01001586 auto ev1 = interned_data->add_event_names();
Eric Seckler56a007d2019-05-02 16:25:14 +01001587 ev1->set_iid(1);
1588 ev1->set_name("ev1");
1589 }
1590 {
1591 auto* packet = trace_.add_packet();
1592 packet->set_trusted_packet_sequence_id(2);
1593 packet->set_incremental_state_cleared(true);
1594 auto* thread_desc = packet->set_thread_descriptor();
1595 thread_desc->set_pid(15);
1596 thread_desc->set_tid(17);
1597 thread_desc->set_reference_timestamp_us(995);
1598 thread_desc->set_reference_thread_time_us(3000);
1599 }
1600 {
1601 auto* packet = trace_.add_packet();
1602 packet->set_trusted_packet_sequence_id(2);
1603 auto* event = packet->set_track_event();
1604 event->set_timestamp_delta_us(10); // absolute: 1005.
1605 event->set_thread_time_delta_us(5); // absolute: 3005.
1606 event->add_category_iids(1);
1607 auto* legacy_event = event->set_legacy_event();
1608 legacy_event->set_name_iid(1);
1609 legacy_event->set_phase('B');
1610
1611 auto* interned_data = packet->set_interned_data();
1612 auto cat1 = interned_data->add_event_categories();
1613 cat1->set_iid(1);
1614 cat1->set_name("cat1");
Eric Seckler0c460ef2019-08-14 15:42:36 +01001615 auto ev2 = interned_data->add_event_names();
Eric Seckler56a007d2019-05-02 16:25:14 +01001616 ev2->set_iid(1);
1617 ev2->set_name("ev2");
1618 }
1619 {
1620 auto* packet = trace_.add_packet();
1621 packet->set_trusted_packet_sequence_id(1);
1622 auto* event = packet->set_track_event();
1623 event->set_timestamp_delta_us(10); // absolute: 1020.
1624 event->set_thread_time_delta_us(5); // absolute: 2010.
1625 event->add_category_iids(1);
1626 auto* legacy_event = event->set_legacy_event();
1627 legacy_event->set_name_iid(1);
1628 legacy_event->set_phase('E');
1629 }
1630 {
1631 auto* packet = trace_.add_packet();
1632 packet->set_trusted_packet_sequence_id(2);
1633 auto* event = packet->set_track_event();
1634 event->set_timestamp_delta_us(10); // absolute: 1015.
1635 event->set_thread_time_delta_us(5); // absolute: 3015.
1636 event->add_category_iids(1);
1637 auto* legacy_event = event->set_legacy_event();
1638 legacy_event->set_name_iid(1);
1639 legacy_event->set_phase('E');
1640 }
1641
1642 Tokenize();
1643
1644 EXPECT_CALL(*process_, UpdateThread(16, 15))
1645 .Times(2)
1646 .WillRepeatedly(Return(1));
1647 EXPECT_CALL(*process_, UpdateThread(17, 15))
1648 .Times(2)
1649 .WillRepeatedly(Return(2));
1650
Eric Secklerb32cacf2019-09-27 16:51:19 +01001651 TraceStorage::Thread thread(16);
1652 thread.upid = 1u;
1653 EXPECT_CALL(*storage_, GetThread(1))
1654 .Times(2)
1655 .WillRepeatedly(testing::ReturnRef(thread));
1656
1657 TraceStorage::Thread thread2(17);
1658 thread2.upid = 1u;
1659 EXPECT_CALL(*storage_, GetThread(2))
1660 .Times(2)
1661 .WillRepeatedly(testing::ReturnRef(thread2));
1662
Lalit Maganti21b21632019-09-28 16:50:23 +01001663 constexpr TrackId thread_2_track = 0u;
1664 constexpr TrackId thread_1_track = 1u;
Eric Seckler56a007d2019-05-02 16:25:14 +01001665 InSequence in_sequence; // Below slices should be sorted by timestamp.
1666
1667 EXPECT_CALL(*storage_, InternString(base::StringView("cat1")))
1668 .WillOnce(Return(1));
1669 EXPECT_CALL(*storage_, InternString(base::StringView("ev2")))
1670 .WillOnce(Return(2));
1671
Lalit Maganti21b21632019-09-28 16:50:23 +01001672 EXPECT_CALL(*slice_, Begin(1005000, thread_2_track, 2, RefType::kRefUtid,
1673 StringId(1), StringId(2), _));
Eric Seckler56a007d2019-05-02 16:25:14 +01001674
1675 EXPECT_CALL(*storage_, InternString(base::StringView("cat1")))
1676 .WillOnce(Return(1));
1677 EXPECT_CALL(*storage_, InternString(base::StringView("ev1")))
1678 .WillOnce(Return(3));
1679
Lalit Maganti21b21632019-09-28 16:50:23 +01001680 EXPECT_CALL(*slice_, Begin(1010000, thread_1_track, 1, RefType::kRefUtid,
1681 StringId(1), StringId(3), _));
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001682 EXPECT_CALL(*slice_,
Lalit Maganti21b21632019-09-28 16:50:23 +01001683 End(1015000, thread_2_track, StringId(1), StringId(2), _));
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001684 EXPECT_CALL(*slice_,
Lalit Maganti21b21632019-09-28 16:50:23 +01001685 End(1020000, thread_1_track, StringId(1), StringId(3), _));
Eric Seckler56a007d2019-05-02 16:25:14 +01001686
1687 context_.sorter->ExtractEventsForced();
1688}
1689
Eric Secklerc93823e2019-06-03 16:49:19 +01001690TEST_F(ProtoTraceParserTest, TrackEventWithDebugAnnotations) {
Eric Secklerc93823e2019-06-03 16:49:19 +01001691 context_.sorter.reset(new TraceSorter(
1692 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
1693 MockArgsTracker args(&context_);
1694
1695 {
1696 auto* packet = trace_.add_packet();
1697 packet->set_trusted_packet_sequence_id(1);
1698 packet->set_incremental_state_cleared(true);
1699 auto* thread_desc = packet->set_thread_descriptor();
1700 thread_desc->set_pid(15);
1701 thread_desc->set_tid(16);
1702 thread_desc->set_reference_timestamp_us(1000);
1703 thread_desc->set_reference_thread_time_us(2000);
1704 }
1705 {
1706 auto* packet = trace_.add_packet();
1707 packet->set_trusted_packet_sequence_id(1);
1708 auto* event = packet->set_track_event();
1709 event->set_timestamp_delta_us(10); // absolute: 1010.
1710 event->set_thread_time_delta_us(5); // absolute: 2005.
1711 event->add_category_iids(1);
1712 auto* annotation1 = event->add_debug_annotations();
1713 annotation1->set_name_iid(1);
1714 annotation1->set_uint_value(10u);
1715 auto* annotation2 = event->add_debug_annotations();
1716 annotation2->set_name_iid(2);
1717 auto* nested = annotation2->set_nested_value();
1718 nested->set_nested_type(protos::pbzero::DebugAnnotation::NestedValue::DICT);
1719 nested->add_dict_keys("child1");
1720 nested->add_dict_keys("child2");
1721 auto* child1 = nested->add_dict_values();
1722 child1->set_nested_type(
1723 protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
1724 child1->set_bool_value(true);
1725 auto* child2 = nested->add_dict_values();
1726 child2->set_nested_type(
1727 protos::pbzero::DebugAnnotation::NestedValue::ARRAY);
1728 auto* child21 = child2->add_array_values();
1729 child21->set_nested_type(
1730 protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
1731 child21->set_string_value("child21");
1732 auto* child22 = child2->add_array_values();
1733 child22->set_nested_type(
1734 protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
1735 child22->set_double_value(2.2);
1736 auto* child23 = child2->add_array_values();
1737 child23->set_nested_type(
1738 protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
1739 child23->set_int_value(23);
1740 auto* legacy_event = event->set_legacy_event();
1741 legacy_event->set_name_iid(1);
1742 legacy_event->set_phase('B');
1743
1744 auto* interned_data = packet->set_interned_data();
1745 auto cat1 = interned_data->add_event_categories();
1746 cat1->set_iid(1);
1747 cat1->set_name("cat1");
Eric Seckler0c460ef2019-08-14 15:42:36 +01001748 auto ev1 = interned_data->add_event_names();
Eric Secklerc93823e2019-06-03 16:49:19 +01001749 ev1->set_iid(1);
1750 ev1->set_name("ev1");
1751 auto an1 = interned_data->add_debug_annotation_names();
1752 an1->set_iid(1);
1753 an1->set_name("an1");
1754 auto an2 = interned_data->add_debug_annotation_names();
1755 an2->set_iid(2);
1756 an2->set_name("an2");
1757 }
1758 {
1759 auto* packet = trace_.add_packet();
1760 packet->set_trusted_packet_sequence_id(1);
1761 auto* event = packet->set_track_event();
1762 event->set_timestamp_delta_us(10); // absolute: 1020.
1763 event->set_thread_time_delta_us(5); // absolute: 2010.
1764 event->add_category_iids(1);
1765 auto* annotation3 = event->add_debug_annotations();
1766 annotation3->set_name_iid(3);
1767 annotation3->set_int_value(-3);
1768 auto* annotation4 = event->add_debug_annotations();
1769 annotation4->set_name_iid(4);
1770 annotation4->set_bool_value(true);
1771 auto* annotation5 = event->add_debug_annotations();
1772 annotation5->set_name_iid(5);
1773 annotation5->set_double_value(-5.5);
1774 auto* annotation6 = event->add_debug_annotations();
1775 annotation6->set_name_iid(6);
1776 annotation6->set_pointer_value(20u);
1777 auto* annotation7 = event->add_debug_annotations();
1778 annotation7->set_name_iid(7);
1779 annotation7->set_string_value("val7");
1780 auto* annotation8 = event->add_debug_annotations();
1781 annotation8->set_name_iid(8);
1782 annotation8->set_legacy_json_value("val8");
1783 auto* legacy_event = event->set_legacy_event();
1784 legacy_event->set_name_iid(1);
1785 legacy_event->set_phase('E');
1786
1787 auto* interned_data = packet->set_interned_data();
1788 auto an3 = interned_data->add_debug_annotation_names();
1789 an3->set_iid(3);
1790 an3->set_name("an3");
1791 auto an4 = interned_data->add_debug_annotation_names();
1792 an4->set_iid(4);
1793 an4->set_name("an4");
1794 auto an5 = interned_data->add_debug_annotation_names();
1795 an5->set_iid(5);
1796 an5->set_name("an5");
1797 auto an6 = interned_data->add_debug_annotation_names();
1798 an6->set_iid(6);
1799 an6->set_name("an6");
1800 auto an7 = interned_data->add_debug_annotation_names();
1801 an7->set_iid(7);
1802 an7->set_name("an7");
1803 auto an8 = interned_data->add_debug_annotation_names();
1804 an8->set_iid(8);
1805 an8->set_name("an8");
1806 }
1807
1808 Tokenize();
1809
1810 EXPECT_CALL(*process_, UpdateThread(16, 15))
1811 .Times(2)
1812 .WillRepeatedly(Return(1));
1813
Eric Secklerb32cacf2019-09-27 16:51:19 +01001814 TraceStorage::Thread thread(16);
1815 thread.upid = 1u;
1816 EXPECT_CALL(*storage_, GetThread(1))
1817 .Times(2)
1818 .WillRepeatedly(testing::ReturnRef(thread));
1819
Lalit Maganti21b21632019-09-28 16:50:23 +01001820 constexpr TrackId track = 0u;
Eric Secklerc93823e2019-06-03 16:49:19 +01001821 InSequence in_sequence; // Below slices should be sorted by timestamp.
1822
1823 EXPECT_CALL(*storage_, InternString(base::StringView("cat1")))
1824 .WillOnce(Return(1));
1825 EXPECT_CALL(*storage_, InternString(base::StringView("ev1")))
1826 .WillOnce(Return(2));
Lalit Maganti21b21632019-09-28 16:50:23 +01001827 EXPECT_CALL(*slice_, Begin(1010000, track, 1, RefType::kRefUtid, StringId(1),
1828 StringId(2), _))
1829 .WillOnce(DoAll(InvokeArgument<6>(&args, 1u), Return(1u)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001830 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an1")))
1831 .WillOnce(Return(3));
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001832 EXPECT_CALL(args, AddArg(1u, StringId(3), StringId(3),
1833 Variadic::UnsignedInteger(10u)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001834
1835 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2")))
1836 .WillOnce(Return(4));
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001837 EXPECT_CALL(*storage_, GetString(StringId(4))).WillOnce(Return("debug.an2"));
Eric Secklerc93823e2019-06-03 16:49:19 +01001838 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2.child1")))
1839 .Times(2)
1840 .WillRepeatedly(Return(5));
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001841 EXPECT_CALL(args,
1842 AddArg(1u, StringId(5), StringId(5), Variadic::Boolean(true)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001843
1844 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2.child2")))
1845 .WillOnce(Return(6));
1846 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2.child2[0]")))
1847 .WillOnce(Return(7));
1848 EXPECT_CALL(*storage_, InternString(base::StringView("child21")))
1849 .WillOnce(Return(8));
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001850 EXPECT_CALL(args, AddArg(1u, StringId(6), StringId(7),
1851 Variadic::String(StringId(8))));
Eric Secklerc93823e2019-06-03 16:49:19 +01001852
1853 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2.child2")))
1854 .WillOnce(Return(6));
1855 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2.child2[1]")))
1856 .WillOnce(Return(9));
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001857 EXPECT_CALL(args, AddArg(1u, StringId(6), StringId(9), Variadic::Real(2.2)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001858
1859 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2.child2")))
1860 .WillOnce(Return(6));
1861 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2.child2[2]")))
1862 .WillOnce(Return(10));
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001863 EXPECT_CALL(args,
1864 AddArg(1u, StringId(6), StringId(10), Variadic::Integer(23)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001865
Lalit Maganti21b21632019-09-28 16:50:23 +01001866 EXPECT_CALL(*slice_, End(1020000, track, StringId(1), StringId(2), _))
1867 .WillOnce(DoAll(InvokeArgument<4>(&args, 1u), Return(1u)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001868
1869 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an3")))
1870 .WillOnce(Return(11));
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001871 EXPECT_CALL(args,
1872 AddArg(1u, StringId(11), StringId(11), Variadic::Integer(-3)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001873 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an4")))
1874 .WillOnce(Return(12));
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001875 EXPECT_CALL(args,
1876 AddArg(1u, StringId(12), StringId(12), Variadic::Boolean(true)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001877 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an5")))
1878 .WillOnce(Return(13));
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001879 EXPECT_CALL(args,
1880 AddArg(1u, StringId(13), StringId(13), Variadic::Real(-5.5)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001881 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an6")))
1882 .WillOnce(Return(14));
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001883 EXPECT_CALL(args,
1884 AddArg(1u, StringId(14), StringId(14), Variadic::Pointer(20u)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001885 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an7")))
1886 .WillOnce(Return(15));
1887 EXPECT_CALL(*storage_, InternString(base::StringView("val7")))
1888 .WillOnce(Return(16));
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001889 EXPECT_CALL(args,
1890 AddArg(1u, StringId(15), StringId(15), Variadic::String(16)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001891 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an8")))
1892 .WillOnce(Return(17));
1893 EXPECT_CALL(*storage_, InternString(base::StringView("val8")))
1894 .WillOnce(Return(18));
Lalit Maganti1a2936f2019-08-29 17:42:33 +01001895 EXPECT_CALL(args, AddArg(1u, StringId(17), StringId(17), Variadic::Json(18)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001896
1897 context_.sorter->ExtractEventsForced();
1898}
1899
1900TEST_F(ProtoTraceParserTest, TrackEventWithTaskExecution) {
Eric Secklerc93823e2019-06-03 16:49:19 +01001901 context_.sorter.reset(new TraceSorter(
1902 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
1903 MockArgsTracker args(&context_);
1904
1905 {
1906 auto* packet = trace_.add_packet();
1907 packet->set_trusted_packet_sequence_id(1);
1908 packet->set_incremental_state_cleared(true);
1909 auto* thread_desc = packet->set_thread_descriptor();
1910 thread_desc->set_pid(15);
1911 thread_desc->set_tid(16);
1912 thread_desc->set_reference_timestamp_us(1000);
1913 thread_desc->set_reference_thread_time_us(2000);
1914 }
1915 {
1916 auto* packet = trace_.add_packet();
1917 packet->set_trusted_packet_sequence_id(1);
1918 auto* event = packet->set_track_event();
1919 event->set_timestamp_delta_us(10); // absolute: 1010.
1920 event->set_thread_time_delta_us(5); // absolute: 2005.
1921 event->add_category_iids(1);
1922 auto* task_execution = event->set_task_execution();
1923 task_execution->set_posted_from_iid(1);
1924 auto* legacy_event = event->set_legacy_event();
1925 legacy_event->set_name_iid(1);
1926 legacy_event->set_phase('B');
1927
1928 auto* interned_data = packet->set_interned_data();
1929 auto cat1 = interned_data->add_event_categories();
1930 cat1->set_iid(1);
1931 cat1->set_name("cat1");
Eric Seckler0c460ef2019-08-14 15:42:36 +01001932 auto ev1 = interned_data->add_event_names();
Eric Secklerc93823e2019-06-03 16:49:19 +01001933 ev1->set_iid(1);
1934 ev1->set_name("ev1");
1935 auto loc1 = interned_data->add_source_locations();
1936 loc1->set_iid(1);
1937 loc1->set_file_name("file1");
1938 loc1->set_function_name("func1");
Nicolò Mazzucato6261d732019-08-30 13:15:17 +01001939 loc1->set_line_number(42);
Eric Secklerc93823e2019-06-03 16:49:19 +01001940 }
1941
1942 Tokenize();
1943
1944 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillOnce(Return(1));
1945
Eric Secklerb32cacf2019-09-27 16:51:19 +01001946 TraceStorage::Thread thread(16);
1947 thread.upid = 1u;
1948 EXPECT_CALL(*storage_, GetThread(1)).WillOnce(testing::ReturnRef(thread));
1949
Lalit Maganti21b21632019-09-28 16:50:23 +01001950 constexpr TrackId track = 0u;
Eric Secklerc93823e2019-06-03 16:49:19 +01001951 InSequence in_sequence; // Below slices should be sorted by timestamp.
1952
1953 EXPECT_CALL(*storage_, InternString(base::StringView("cat1")))
1954 .WillOnce(Return(1));
1955 EXPECT_CALL(*storage_, InternString(base::StringView("ev1")))
1956 .WillOnce(Return(2));
Lalit Maganti21b21632019-09-28 16:50:23 +01001957 EXPECT_CALL(*slice_, Begin(1010000, track, 1, RefType::kRefUtid, StringId(1),
1958 StringId(2), _))
1959 .WillOnce(DoAll(InvokeArgument<6>(&args, 1u), Return(1u)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001960 EXPECT_CALL(*storage_, InternString(base::StringView("file1")))
1961 .WillOnce(Return(3));
1962 EXPECT_CALL(*storage_, InternString(base::StringView("func1")))
1963 .WillOnce(Return(4));
1964 EXPECT_CALL(args, AddArg(1u, _, _, Variadic::String(3)));
1965 EXPECT_CALL(args, AddArg(1u, _, _, Variadic::String(4)));
Nicolò Mazzucato6261d732019-08-30 13:15:17 +01001966 EXPECT_CALL(args, AddArg(1u, _, _, Variadic::UnsignedInteger(42)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001967
1968 context_.sorter->ExtractEventsForced();
1969}
1970
Nicolò Mazzucato8f75ede2019-08-12 17:36:36 +01001971TEST_F(ProtoTraceParserTest, TrackEventWithLogMessage) {
1972 context_.sorter.reset(new TraceSorter(
1973 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
1974 MockArgsTracker args(&context_);
1975
1976 {
1977 auto* packet = trace_.add_packet();
1978 packet->set_trusted_packet_sequence_id(1);
1979 packet->set_incremental_state_cleared(true);
1980 auto* thread_desc = packet->set_thread_descriptor();
1981 thread_desc->set_pid(15);
1982 thread_desc->set_tid(16);
1983 thread_desc->set_reference_timestamp_us(1000);
1984 thread_desc->set_reference_thread_time_us(2000);
1985 }
1986 {
1987 auto* packet = trace_.add_packet();
1988 packet->set_trusted_packet_sequence_id(1);
1989 auto* event = packet->set_track_event();
1990 event->set_timestamp_delta_us(10); // absolute: 1010.
1991 event->set_thread_time_delta_us(5); // absolute: 2005.
1992 event->add_category_iids(1);
1993
1994 auto* log_message = event->set_log_message();
1995 log_message->set_body_iid(1);
1996 log_message->set_source_location_iid(1);
1997
1998 auto* legacy_event = event->set_legacy_event();
1999 legacy_event->set_name_iid(1);
2000 legacy_event->set_phase('I');
2001
2002 auto* interned_data = packet->set_interned_data();
2003 auto cat1 = interned_data->add_event_categories();
2004 cat1->set_iid(1);
2005 cat1->set_name("cat1");
2006
Eric Seckler0c460ef2019-08-14 15:42:36 +01002007 auto ev1 = interned_data->add_event_names();
Nicolò Mazzucato8f75ede2019-08-12 17:36:36 +01002008 ev1->set_iid(1);
2009 ev1->set_name("ev1");
2010
2011 auto body = interned_data->add_log_message_body();
2012 body->set_iid(1);
2013 body->set_body("body1");
2014
2015 auto loc1 = interned_data->add_source_locations();
2016 loc1->set_iid(1);
2017 loc1->set_file_name("file1");
2018 loc1->set_function_name("func1");
2019 loc1->set_line_number(1);
2020 }
2021
2022 Tokenize();
2023
2024 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillOnce(Return(1));
2025
Eric Secklerb32cacf2019-09-27 16:51:19 +01002026 TraceStorage::Thread thread(16);
2027 thread.upid = 1u;
2028 EXPECT_CALL(*storage_, GetThread(1)).WillOnce(testing::ReturnRef(thread));
2029
Lalit Maganti21b21632019-09-28 16:50:23 +01002030 constexpr TrackId track = 0;
Nicolò Mazzucato8f75ede2019-08-12 17:36:36 +01002031 InSequence in_sequence; // Below slices should be sorted by timestamp.
2032
2033 EXPECT_CALL(*storage_, InternString(base::StringView("cat1")))
2034 .WillOnce(Return(1));
2035 EXPECT_CALL(*storage_, InternString(base::StringView("ev1")))
2036 .WillOnce(Return(2));
2037
Lalit Maganti21b21632019-09-28 16:50:23 +01002038 EXPECT_CALL(*slice_, Scoped(1010000, track, 1, RefType::kRefUtid, StringId(1),
Lalit Maganti1a2936f2019-08-29 17:42:33 +01002039 StringId(2), 0, _))
Lalit Maganti21b21632019-09-28 16:50:23 +01002040 .WillOnce(DoAll(InvokeArgument<7>(&args, 1u), Return(1u)));
Nicolò Mazzucato8f75ede2019-08-12 17:36:36 +01002041
2042 EXPECT_CALL(*storage_, InternString(base::StringView("body1")))
2043 .WillOnce(Return(3));
2044
2045 // Call with logMessageBody (body1 in this case).
Lalit Maganti1a2936f2019-08-29 17:42:33 +01002046 EXPECT_CALL(args, AddArg(1u, _, _, Variadic::String(StringId(3))));
Nicolò Mazzucato8f75ede2019-08-12 17:36:36 +01002047
2048 context_.sorter->ExtractEventsForced();
2049
2050 EXPECT_TRUE(context_.storage->android_logs().size() > 0);
2051 EXPECT_EQ(context_.storage->android_logs().timestamps()[0], 1010000);
2052 EXPECT_EQ(context_.storage->android_logs().msg_ids()[0], 3u);
2053}
2054
Eric Secklerb7e26332019-07-19 12:46:17 +01002055TEST_F(ProtoTraceParserTest, TrackEventParseLegacyEventIntoRawTable) {
2056 context_.sorter.reset(new TraceSorter(
2057 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
2058
2059 {
2060 auto* packet = trace_.add_packet();
2061 packet->set_trusted_packet_sequence_id(1);
2062 packet->set_incremental_state_cleared(true);
2063 auto* thread_desc = packet->set_thread_descriptor();
2064 thread_desc->set_pid(15);
2065 thread_desc->set_tid(16);
2066 thread_desc->set_reference_timestamp_us(1000);
2067 thread_desc->set_reference_thread_time_us(2000);
2068 }
2069 {
2070 auto* packet = trace_.add_packet();
2071 packet->set_trusted_packet_sequence_id(1);
2072 auto* event = packet->set_track_event();
2073 event->set_timestamp_delta_us(10); // absolute: 1010.
2074 event->set_thread_time_delta_us(5); // absolute: 2005.
2075 event->add_category_iids(1);
2076
2077 auto* legacy_event = event->set_legacy_event();
2078 legacy_event->set_name_iid(1);
2079 // Represents a phase that isn't parsed into regular trace processor tables.
2080 legacy_event->set_phase('?');
2081 legacy_event->set_duration_us(23);
2082 legacy_event->set_thread_duration_us(15);
2083 legacy_event->set_global_id(99u);
2084 legacy_event->set_id_scope("scope1");
2085 legacy_event->set_use_async_tts('?');
2086 legacy_event->set_bind_id(98);
2087 legacy_event->set_bind_to_enclosing(true);
2088 legacy_event->set_flow_direction(
2089 protos::pbzero::TrackEvent::LegacyEvent::FLOW_INOUT);
2090
2091 auto* annotation1 = event->add_debug_annotations();
2092 annotation1->set_name_iid(1);
2093 annotation1->set_uint_value(10u);
2094
2095 auto* interned_data = packet->set_interned_data();
2096 auto cat1 = interned_data->add_event_categories();
2097 cat1->set_iid(1);
2098 cat1->set_name("cat1");
Eric Seckler0c460ef2019-08-14 15:42:36 +01002099 auto ev1 = interned_data->add_event_names();
Eric Secklerb7e26332019-07-19 12:46:17 +01002100 ev1->set_iid(1);
2101 ev1->set_name("ev1");
2102 auto an1 = interned_data->add_debug_annotation_names();
2103 an1->set_iid(1);
2104 an1->set_name("an1");
2105 }
2106
2107 Tokenize();
2108
2109 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillOnce(Return(1));
2110
Eric Secklerb32cacf2019-09-27 16:51:19 +01002111 TraceStorage::Thread thread(16);
2112 thread.upid = 1u;
2113 EXPECT_CALL(*storage_, GetThread(1)).WillOnce(testing::ReturnRef(thread));
2114
Eric Secklerb7e26332019-07-19 12:46:17 +01002115 EXPECT_CALL(*storage_, InternString(base::StringView("cat1")))
2116 .WillOnce(Return(1));
2117 EXPECT_CALL(*storage_, InternString(base::StringView("ev1")))
2118 .WillOnce(Return(2));
2119 EXPECT_CALL(*storage_, InternString(base::StringView("scope1")))
Eric Secklerb32cacf2019-09-27 16:51:19 +01002120 .Times(1)
Eric Secklerb7e26332019-07-19 12:46:17 +01002121 .WillRepeatedly(Return(3));
Eric Secklerc34c8fc2019-08-02 10:57:59 +01002122 EXPECT_CALL(*storage_, InternString(base::StringView("?")))
Eric Secklerb7e26332019-07-19 12:46:17 +01002123 .WillOnce(Return(4));
Eric Secklerc34c8fc2019-08-02 10:57:59 +01002124 EXPECT_CALL(*storage_, InternString(base::StringView("debug.an1")))
2125 .WillOnce(Return(5));
Eric Secklerb7e26332019-07-19 12:46:17 +01002126
2127 context_.sorter->ExtractEventsForced();
2128
2129 ::testing::Mock::VerifyAndClearExpectations(storage_);
2130
2131 // Verify raw_events and args contents.
2132 const auto& raw_events = storage_->raw_events();
2133 EXPECT_EQ(raw_events.raw_event_count(), 1u);
2134 EXPECT_EQ(raw_events.timestamps()[0], 1010000);
2135 EXPECT_EQ(raw_events.name_ids()[0],
2136 storage_->InternString("track_event.legacy_event"));
2137 EXPECT_EQ(raw_events.cpus()[0], 0u);
2138 EXPECT_EQ(raw_events.utids()[0], 1u);
2139 EXPECT_EQ(raw_events.arg_set_ids()[0], 1u);
2140
Eric Secklerb32cacf2019-09-27 16:51:19 +01002141 EXPECT_GE(storage_->args().args_count(), 13u);
Eric Secklerb7e26332019-07-19 12:46:17 +01002142
2143 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.category"),
2144 Variadic::String(1u)));
2145 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.name"),
2146 Variadic::String(2u)));
2147 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.phase"),
Eric Secklerc34c8fc2019-08-02 10:57:59 +01002148 Variadic::String(4u)));
Eric Secklerb7e26332019-07-19 12:46:17 +01002149 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.duration_ns"),
2150 Variadic::Integer(23000)));
2151 EXPECT_TRUE(HasArg(1u,
2152 storage_->InternString("legacy_event.thread_timestamp_ns"),
2153 Variadic::Integer(2005000)));
2154 EXPECT_TRUE(HasArg(1u,
2155 storage_->InternString("legacy_event.thread_duration_ns"),
2156 Variadic::Integer(15000)));
2157 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.use_async_tts"),
2158 Variadic::Boolean(true)));
2159 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.global_id"),
2160 Variadic::UnsignedInteger(99u)));
2161 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.id_scope"),
2162 Variadic::String(3u)));
2163 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.bind_id"),
2164 Variadic::UnsignedInteger(98u)));
2165 EXPECT_TRUE(HasArg(1u,
2166 storage_->InternString("legacy_event.bind_to_enclosing"),
2167 Variadic::Boolean(true)));
2168 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.flow_direction"),
2169 Variadic::String(storage_->InternString("inout"))));
Eric Secklerc34c8fc2019-08-02 10:57:59 +01002170 EXPECT_TRUE(HasArg(1u, 5u, Variadic::UnsignedInteger(10u)));
Eric Secklerb7e26332019-07-19 12:46:17 +01002171}
2172
Eric Seckler15ea5df2019-10-14 13:54:07 +01002173TEST_F(ProtoTraceParserTest, TrackEventLegacyTimestampsWithClockSnapshot) {
2174 context_.sorter.reset(new TraceSorter(
2175 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
2176
2177 std::map<ClockTracker::ClockId, int64_t> clock_map;
2178 clock_map[protos::pbzero::ClockSnapshot::Clock::BOOTTIME] = 0u;
2179 clock_map[protos::pbzero::ClockSnapshot::Clock::MONOTONIC] = 1000000u;
2180 clock_->AddSnapshot(clock_map);
2181
2182 {
2183 auto* packet = trace_.add_packet();
2184 packet->set_trusted_packet_sequence_id(1);
2185 packet->set_incremental_state_cleared(true);
2186 auto* thread_desc = packet->set_thread_descriptor();
2187 thread_desc->set_pid(15);
2188 thread_desc->set_tid(16);
2189 thread_desc->set_reference_timestamp_us(1000); // MONOTONIC.
2190 }
2191 {
2192 auto* packet = trace_.add_packet();
2193 packet->set_trusted_packet_sequence_id(1);
2194 auto* event = packet->set_track_event();
2195 event->set_timestamp_delta_us(10); // absolute: 1010 (mon), 10 (boot).
2196 event->add_category_iids(1);
2197 event->set_type(protos::pbzero::TrackEvent::TYPE_SLICE_BEGIN);
2198 auto* legacy_event = event->set_legacy_event();
2199 legacy_event->set_name_iid(1);
2200 }
2201
2202 Tokenize();
2203
2204 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillOnce(Return(1));
2205
2206 TraceStorage::Thread thread(16);
2207 thread.upid = 1u;
2208 EXPECT_CALL(*storage_, GetThread(1)).WillOnce(testing::ReturnRef(thread));
2209
2210 MockArgsTracker args(&context_);
2211
2212 constexpr TrackId track = 0u;
2213 InSequence in_sequence; // Below slices should be sorted by timestamp.
2214
2215 // Timestamp should be adjusted to trace time (BOOTTIME).
2216 EXPECT_CALL(*slice_, Begin(10000, track, 1, RefType::kRefUtid, kNullStringId,
2217 kNullStringId, _));
2218
2219 context_.sorter->ExtractEventsForced();
2220}
2221
Mikhail Khokhlovca34df22019-08-07 16:50:01 +01002222TEST_F(ProtoTraceParserTest, ParseChromeMetadataEventIntoRawTable) {
2223 static const char kStringName[] = "string_name";
2224 static const char kStringValue[] = "string_value";
2225 static const char kIntName[] = "int_name";
2226 static const int kIntValue = 123;
2227
2228 context_.sorter.reset(new TraceSorter(
2229 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
2230
2231 {
2232 auto* packet = trace_.add_packet();
2233 packet->set_trusted_packet_sequence_id(1);
2234 auto* bundle = packet->set_chrome_events();
2235 auto* metadata = bundle->add_metadata();
2236 metadata->set_name(kStringName);
2237 metadata->set_string_value(kStringValue);
2238 metadata = bundle->add_metadata();
2239 metadata->set_name(kIntName);
2240 metadata->set_int_value(kIntValue);
2241 }
2242
2243 Tokenize();
2244 context_.sorter->ExtractEventsForced();
2245
2246 // Verify raw_events and args contents.
2247 const auto& raw_events = storage_->raw_events();
2248 EXPECT_EQ(raw_events.raw_event_count(), 1u);
2249 EXPECT_EQ(raw_events.name_ids()[0],
2250 storage_->InternString("chrome_event.metadata"));
2251 EXPECT_EQ(raw_events.arg_set_ids()[0], 1u);
2252
2253 EXPECT_EQ(storage_->args().args_count(), 2u);
2254 EXPECT_TRUE(HasArg(1u, storage_->InternString(kStringName),
2255 Variadic::String(storage_->InternString(kStringValue))));
2256 EXPECT_TRUE(HasArg(1u, storage_->InternString(kIntName),
2257 Variadic::Integer(kIntValue)));
2258}
2259
Mikhail Khokhlovfd746552019-08-15 14:54:29 +01002260TEST_F(ProtoTraceParserTest, ParseChromeLegacyFtraceIntoRawTable) {
2261 static const char kDataPart0[] = "aaa";
2262 static const char kDataPart1[] = "bbb";
2263 static const char kFullData[] = "aaabbb";
2264
2265 context_.sorter.reset(new TraceSorter(
2266 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
2267
2268 {
2269 auto* packet = trace_.add_packet();
2270 packet->set_trusted_packet_sequence_id(1);
2271 auto* bundle = packet->set_chrome_events();
2272 bundle->add_legacy_ftrace_output(kDataPart0);
2273 bundle->add_legacy_ftrace_output(kDataPart1);
2274 }
2275
2276 Tokenize();
2277
2278 context_.sorter->ExtractEventsForced();
2279
2280 // Verify raw_events and args contents.
2281 const auto& raw_events = storage_->raw_events();
2282 EXPECT_EQ(raw_events.raw_event_count(), 1u);
2283 EXPECT_EQ(raw_events.name_ids()[0],
2284 storage_->InternString("chrome_event.legacy_system_trace"));
2285 EXPECT_EQ(raw_events.arg_set_ids()[0], 1u);
2286
2287 EXPECT_EQ(storage_->args().args_count(), 1u);
2288 EXPECT_TRUE(HasArg(1u, storage_->InternString("data"),
2289 Variadic::String(storage_->InternString(kFullData))));
2290}
2291
2292TEST_F(ProtoTraceParserTest, ParseChromeLegacyJsonIntoRawTable) {
2293 static const char kUserTraceEvent[] = "{\"user\":1}";
2294
2295 context_.sorter.reset(new TraceSorter(
2296 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
2297
2298 {
2299 auto* packet = trace_.add_packet();
2300 packet->set_trusted_packet_sequence_id(1);
2301 auto* bundle = packet->set_chrome_events();
2302 auto* user_trace = bundle->add_legacy_json_trace();
2303 user_trace->set_type(protos::pbzero::ChromeLegacyJsonTrace::USER_TRACE);
2304 user_trace->set_data(kUserTraceEvent);
2305 }
2306
2307 Tokenize();
2308
2309 context_.sorter->ExtractEventsForced();
2310
2311 // Verify raw_events and args contents.
2312 const auto& raw_events = storage_->raw_events();
2313 EXPECT_EQ(raw_events.raw_event_count(), 1u);
2314 EXPECT_EQ(raw_events.name_ids()[0],
2315 storage_->InternString("chrome_event.legacy_user_trace"));
2316 EXPECT_EQ(raw_events.arg_set_ids()[0], 1u);
2317
2318 EXPECT_EQ(storage_->args().args_count(), 1u);
Eric Seckler13b84b32019-10-04 12:00:38 +01002319 EXPECT_TRUE(
2320 HasArg(1u, storage_->InternString("data"),
2321 Variadic::String(storage_->InternString(kUserTraceEvent))));
Mikhail Khokhlovfd746552019-08-15 14:54:29 +01002322}
2323
Mikhail Khokhlovb1fe42a2019-05-23 13:58:05 +01002324TEST_F(ProtoTraceParserTest, LoadChromeBenchmarkMetadata) {
2325 static const char kName[] = "name";
Ryan Savitski0476ee92019-07-09 14:29:33 +01002326 static const char kTag1[] = "tag1";
2327 static const char kTag2[] = "tag2";
Mikhail Khokhlovb1fe42a2019-05-23 13:58:05 +01002328
Mikhail Khokhlovb1fe42a2019-05-23 13:58:05 +01002329 context_.sorter.reset(new TraceSorter(
2330 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
2331
2332 auto* metadata = trace_.add_packet()->set_chrome_benchmark_metadata();
2333 metadata->set_benchmark_name(kName);
2334 metadata->add_story_tags(kTag1);
2335 metadata->add_story_tags(kTag2);
2336
2337 Tokenize();
2338
2339 EXPECT_CALL(*storage_, InternString(base::StringView(kName)))
2340 .WillOnce(Return(1));
2341 EXPECT_CALL(*storage_, InternString(base::StringView(kTag1)))
2342 .WillOnce(Return(2));
2343 EXPECT_CALL(*storage_, InternString(base::StringView(kTag2)))
2344 .WillOnce(Return(3));
Mikhail Khokhlovb1fe42a2019-05-23 13:58:05 +01002345
2346 context_.sorter->ExtractEventsForced();
Ryan Savitski0476ee92019-07-09 14:29:33 +01002347
2348 const auto& meta_keys = storage_->metadata().keys();
2349 const auto& meta_values = storage_->metadata().values();
Ryan Savitski37d94752019-07-09 19:57:39 +01002350 EXPECT_EQ(meta_keys.size(), 3u);
Ryan Savitski0476ee92019-07-09 14:29:33 +01002351 std::vector<std::pair<metadata::KeyIDs, Variadic>> meta_entries;
2352 for (size_t i = 0; i < meta_keys.size(); i++) {
2353 meta_entries.emplace_back(std::make_pair(meta_keys[i], meta_values[i]));
2354 }
2355 EXPECT_THAT(
2356 meta_entries,
2357 UnorderedElementsAreArray(
2358 {std::make_pair(metadata::benchmark_name, Variadic::String(1)),
2359 std::make_pair(metadata::benchmark_story_tags, Variadic::String(2)),
2360 std::make_pair(metadata::benchmark_story_tags,
2361 Variadic::String(3))}));
2362}
2363
2364TEST_F(ProtoTraceParserTest, AndroidPackagesList) {
2365 auto* packet = trace_.add_packet();
2366 auto* pkg_list = packet->set_packages_list();
2367
2368 pkg_list->set_read_error(false);
2369 pkg_list->set_parse_error(true);
2370 {
2371 auto* pkg = pkg_list->add_packages();
2372 pkg->set_name("com.test.app");
2373 pkg->set_uid(1000);
2374 pkg->set_debuggable(false);
2375 pkg->set_profileable_from_shell(true);
2376 pkg->set_version_code(42);
2377 }
2378 {
2379 auto* pkg = pkg_list->add_packages();
2380 pkg->set_name("com.test.app2");
2381 pkg->set_uid(1001);
2382 pkg->set_debuggable(false);
2383 pkg->set_profileable_from_shell(false);
2384 pkg->set_version_code(43);
2385 }
2386
2387 Tokenize();
2388
2389 // Packet-level errors reflected in stats storage.
2390 const auto& stats = context_.storage->stats();
2391 EXPECT_FALSE(stats[stats::packages_list_has_read_errors].value);
2392 EXPECT_TRUE(stats[stats::packages_list_has_parse_errors].value);
2393
2394 // Expect two metadata rows, each with an int_value of a separate arg set id.
2395 // The relevant arg sets have the info about the packages. To simplify test
2396 // structure, make an assumption that metadata storage is filled in in the
2397 // FIFO order of seen packages.
2398 const auto& args = context_.storage->args();
2399 const auto& metadata = context_.storage->metadata();
2400 const auto& meta_keys = metadata.keys();
2401 const auto& meta_values = metadata.values();
2402
2403 ASSERT_TRUE(std::count(meta_keys.cbegin(), meta_keys.cend(),
2404 metadata::android_packages_list) == 2);
2405
2406 auto first_meta_idx = std::distance(
2407 meta_keys.cbegin(), std::find(meta_keys.cbegin(), meta_keys.cend(),
2408 metadata::android_packages_list));
2409 auto second_meta_idx = std::distance(
2410 meta_keys.cbegin(),
2411 std::find(meta_keys.cbegin() + first_meta_idx + 1, meta_keys.cend(),
2412 metadata::android_packages_list));
2413
2414 uint32_t first_set_id = static_cast<uint32_t>(
2415 meta_values[static_cast<size_t>(first_meta_idx)].int_value);
2416 uint32_t second_set_id = static_cast<uint32_t>(
2417 meta_values[static_cast<size_t>(second_meta_idx)].int_value);
2418
2419 // helper to look up arg values
2420 auto find_arg = [&args, this](ArgSetId set_id, const char* arg_name) {
2421 for (size_t i = 0; i < args.set_ids().size(); i++) {
2422 if (args.set_ids()[i] == set_id &&
2423 args.keys()[i] == storage_->InternString(arg_name))
2424 return args.arg_values()[i];
2425 }
2426 PERFETTO_FATAL("Didn't find expected argument");
2427 };
2428
2429 auto first_name_id = find_arg(first_set_id, "name").string_value;
2430 EXPECT_STREQ(storage_->GetString(first_name_id).c_str(), "com.test.app");
Ryan Savitski944f7de2019-07-11 18:05:55 +01002431 EXPECT_EQ(find_arg(first_set_id, "uid").uint_value, 1000u);
Ryan Savitskiafdf0f82019-07-11 12:49:44 +01002432 EXPECT_EQ(find_arg(first_set_id, "debuggable").bool_value, false);
2433 EXPECT_EQ(find_arg(first_set_id, "profileable_from_shell").bool_value, true);
Ryan Savitski0476ee92019-07-09 14:29:33 +01002434 EXPECT_EQ(find_arg(first_set_id, "version_code").int_value, 42);
2435
2436 auto second_name_id = find_arg(second_set_id, "name").string_value;
2437 EXPECT_STREQ(storage_->GetString(second_name_id).c_str(), "com.test.app2");
Ryan Savitski944f7de2019-07-11 18:05:55 +01002438 EXPECT_EQ(find_arg(second_set_id, "uid").uint_value, 1001u);
Ryan Savitskiafdf0f82019-07-11 12:49:44 +01002439 EXPECT_EQ(find_arg(second_set_id, "debuggable").bool_value, false);
2440 EXPECT_EQ(find_arg(second_set_id, "profileable_from_shell").bool_value,
2441 false);
Ryan Savitski0476ee92019-07-09 14:29:33 +01002442 EXPECT_EQ(find_arg(second_set_id, "version_code").int_value, 43);
Mikhail Khokhlovb1fe42a2019-05-23 13:58:05 +01002443}
2444
Oystein Eftevaag7f64c102019-08-29 10:27:31 -07002445TEST_F(ProtoTraceParserTest, ParseCPUProfileSamplesIntoTable) {
2446 {
2447 auto* packet = trace_.add_packet();
2448 packet->set_trusted_packet_sequence_id(1);
2449 packet->set_incremental_state_cleared(true);
2450
2451 auto* thread_desc = packet->set_thread_descriptor();
2452 thread_desc->set_pid(15);
2453 thread_desc->set_tid(16);
2454 thread_desc->set_reference_timestamp_us(1);
2455 thread_desc->set_reference_thread_time_us(2);
2456
2457 auto* interned_data = packet->set_interned_data();
2458
2459 auto mapping = interned_data->add_mappings();
2460 mapping->set_iid(1);
2461
2462 auto frame = interned_data->add_frames();
2463 frame->set_iid(1);
2464 frame->set_rel_pc(0x42);
2465 frame->set_mapping_id(1);
2466
2467 auto frame2 = interned_data->add_frames();
2468 frame2->set_iid(2);
2469 frame2->set_rel_pc(0x4242);
2470 frame2->set_mapping_id(1);
2471
2472 auto callstack = interned_data->add_callstacks();
2473 callstack->set_iid(1);
2474 callstack->add_frame_ids(1);
2475
2476 auto callstack2 = interned_data->add_callstacks();
2477 callstack2->set_iid(42);
2478 callstack2->add_frame_ids(2);
2479 }
2480
2481 {
2482 auto* packet = trace_.add_packet();
2483 packet->set_trusted_packet_sequence_id(1);
2484
2485 auto* samples = packet->set_streaming_profile_packet();
2486 samples->add_callstack_iid(42);
2487 samples->add_timestamp_delta_us(10);
2488
2489 samples->add_callstack_iid(1);
2490 samples->add_timestamp_delta_us(15);
2491 }
2492
2493 {
2494 auto* packet = trace_.add_packet();
2495 packet->set_trusted_packet_sequence_id(1);
2496 auto* samples = packet->set_streaming_profile_packet();
2497
2498 samples->add_callstack_iid(42);
2499 samples->add_timestamp_delta_us(42);
2500 }
2501
2502 EXPECT_CALL(*process_, UpdateThread(16, 15))
2503 .Times(2)
2504 .WillRepeatedly(Return(1));
2505
2506 Tokenize();
2507
2508 // Verify cpu_profile_samples.
2509 const auto& samples = storage_->cpu_profile_stack_samples();
2510 EXPECT_EQ(samples.size(), 3u);
2511
2512 EXPECT_EQ(samples.timestamps()[0], 1010);
2513 EXPECT_EQ(samples.callsite_ids()[0], 0);
2514 EXPECT_EQ(samples.utids()[0], 1u);
2515
2516 EXPECT_EQ(samples.timestamps()[1], 1025);
2517 EXPECT_EQ(samples.callsite_ids()[1], 1);
2518 EXPECT_EQ(samples.utids()[1], 1u);
2519
2520 EXPECT_EQ(samples.timestamps()[2], 1067);
2521 EXPECT_EQ(samples.callsite_ids()[2], 0);
2522 EXPECT_EQ(samples.utids()[2], 1u);
2523}
2524
Lalit Maganti93b76362018-06-01 03:03:58 +01002525} // namespace
2526} // namespace trace_processor
2527} // namespace perfetto