blob: 29860c9e620188563fe837140bf76b744f120917 [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
Eric Seckler137a4672019-10-24 08:51:14 +010017#include "src/trace_processor/importers/proto/proto_trace_tokenizer.h"
Lalit Maganti93b76362018-06-01 03:03:58 +010018
Eric Secklerac2ea612019-10-21 16:44:39 +010019#include "perfetto/base/logging.h"
Primiano Tucci2c5488f2019-06-01 03:27:28 +010020#include "perfetto/ext/base/string_view.h"
Primiano Tuccie5f11682019-03-22 07:21:49 +000021#include "perfetto/protozero/scattered_heap_buffer.h"
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +000022#include "src/trace_processor/args_tracker.h"
Eric Seckler15ea5df2019-10-14 13:54:07 +010023#include "src/trace_processor/clock_tracker.h"
Isabelle Taylora97c5f52018-10-23 17:36:12 +010024#include "src/trace_processor/event_tracker.h"
Eric Seckleracfe35b2019-10-18 15:50:17 +010025#include "src/trace_processor/importers/ftrace/ftrace_module.h"
Eric Secklerd3795132019-10-21 16:43:10 +010026#include "src/trace_processor/importers/ftrace/sched_event_tracker.h"
Eric Seckler87ede882019-10-18 10:48:36 +010027#include "src/trace_processor/importers/proto/proto_importer_module.h"
Eric Seckler137a4672019-10-24 08:51:14 +010028#include "src/trace_processor/importers/proto/proto_trace_parser.h"
Eric Seckler87ede882019-10-18 10:48:36 +010029#include "src/trace_processor/importers/proto/track_event_module.h"
Lalit Magantiededb0e2020-01-08 12:50:34 +000030#include "src/trace_processor/metadata_tracker.h"
Primiano Tucci0d72a312018-08-07 14:42:45 +010031#include "src/trace_processor/process_tracker.h"
Mikhail Khokhlov692087e2019-12-11 10:53:45 +000032#include "src/trace_processor/register_additional_modules.h"
Eric Seckler56a007d2019-05-02 16:25:14 +010033#include "src/trace_processor/slice_tracker.h"
Oystein Eftevaag7f64c102019-08-29 10:27:31 -070034#include "src/trace_processor/stack_profile_tracker.h"
Lalit Maganti7010b332020-02-07 10:51:15 +000035#include "src/trace_processor/storage/metadata.h"
36#include "src/trace_processor/storage/trace_storage.h"
Primiano Tuccid933d912018-09-04 09:15:07 +010037#include "src/trace_processor/trace_sorter.h"
Lalit Maganti4ea78d92019-09-20 20:20:41 +010038#include "src/trace_processor/track_tracker.h"
Primiano Tucci919ca1e2019-08-21 20:26:58 +020039#include "test/gtest_and_gmock.h"
Primiano Tucci0d72a312018-08-07 14:42:45 +010040
Primiano Tucci355b8c82019-08-29 08:37:51 +020041#include "protos/perfetto/common/sys_stats_counters.pbzero.h"
42#include "protos/perfetto/trace/android/packages_list.pbzero.h"
43#include "protos/perfetto/trace/chrome/chrome_benchmark_metadata.pbzero.h"
44#include "protos/perfetto/trace/chrome/chrome_trace_event.pbzero.h"
Eric Seckler15ea5df2019-10-14 13:54:07 +010045#include "protos/perfetto/trace/clock_snapshot.pbzero.h"
Primiano Tucci355b8c82019-08-29 08:37:51 +020046#include "protos/perfetto/trace/ftrace/ftrace.pbzero.h"
47#include "protos/perfetto/trace/ftrace/ftrace_event.pbzero.h"
48#include "protos/perfetto/trace/ftrace/ftrace_event_bundle.pbzero.h"
49#include "protos/perfetto/trace/ftrace/generic.pbzero.h"
50#include "protos/perfetto/trace/ftrace/power.pbzero.h"
51#include "protos/perfetto/trace/ftrace/sched.pbzero.h"
52#include "protos/perfetto/trace/ftrace/task.pbzero.h"
53#include "protos/perfetto/trace/interned_data/interned_data.pbzero.h"
Oystein Eftevaag7f64c102019-08-29 10:27:31 -070054#include "protos/perfetto/trace/profiling/profile_packet.pbzero.h"
Primiano Tucci355b8c82019-08-29 08:37:51 +020055#include "protos/perfetto/trace/ps/process_tree.pbzero.h"
56#include "protos/perfetto/trace/sys_stats/sys_stats.pbzero.h"
57#include "protos/perfetto/trace/trace.pbzero.h"
58#include "protos/perfetto/trace/trace_packet.pbzero.h"
59#include "protos/perfetto/trace/track_event/debug_annotation.pbzero.h"
Eric Seckler02cdcef2019-10-14 08:56:28 +010060#include "protos/perfetto/trace/track_event/log_message.pbzero.h"
Eric Seckler7d128472020-01-13 10:03:51 +000061#include "protos/perfetto/trace/track_event/process_descriptor.pbzero.h"
Eric Seckler02cdcef2019-10-14 08:56:28 +010062#include "protos/perfetto/trace/track_event/source_location.pbzero.h"
Primiano Tucci355b8c82019-08-29 08:37:51 +020063#include "protos/perfetto/trace/track_event/task_execution.pbzero.h"
64#include "protos/perfetto/trace/track_event/thread_descriptor.pbzero.h"
Eric Secklerb32cacf2019-09-27 16:51:19 +010065#include "protos/perfetto/trace/track_event/track_descriptor.pbzero.h"
Primiano Tucci355b8c82019-08-29 08:37:51 +020066#include "protos/perfetto/trace/track_event/track_event.pbzero.h"
Lalit Maganti93b76362018-06-01 03:03:58 +010067
68namespace perfetto {
69namespace trace_processor {
70namespace {
71
Primiano Tucci2da5d2e2018-08-10 14:23:31 +010072using ::testing::_;
Lalit Maganti35622b72018-06-06 12:03:11 +010073using ::testing::Args;
Primiano Tucci711de1f2019-03-04 11:11:33 +000074using ::testing::AtLeast;
Lalit Maganti35622b72018-06-06 12:03:11 +010075using ::testing::ElementsAreArray;
76using ::testing::Eq;
Eric Seckler56a007d2019-05-02 16:25:14 +010077using ::testing::InSequence;
Ryan Savitski0476ee92019-07-09 14:29:33 +010078using ::testing::Invoke;
Eric Secklerd3b89d52019-07-10 15:36:29 +010079using ::testing::InvokeArgument;
Isabelle Taylor54ce7052018-10-01 14:00:15 +010080using ::testing::NiceMock;
Eric Seckler56a007d2019-05-02 16:25:14 +010081using ::testing::Pointwise;
82using ::testing::Return;
Lalit Maganti5228f362020-01-15 13:45:56 +000083using ::testing::ReturnRef;
Ryan Savitski0476ee92019-07-09 14:29:33 +010084using ::testing::UnorderedElementsAreArray;
Lalit Maganti93b76362018-06-01 03:03:58 +010085
Eric Secklerc36f22e2019-10-28 10:08:12 +000086namespace {
Primiano Tucci919ca1e2019-08-21 20:26:58 +020087MATCHER_P(DoubleEq, exp, "Double matcher that satisfies -Wfloat-equal") {
88 // The IEEE standard says that any comparison operation involving
89 // a NAN must return false.
Primiano Tuccid3c62b42019-08-22 07:07:59 +020090 double d_exp = exp;
91 double d_arg = arg;
92 if (isnan(d_exp) || isnan(d_arg))
Primiano Tucci919ca1e2019-08-21 20:26:58 +020093 return false;
Primiano Tuccid3c62b42019-08-22 07:07:59 +020094 return fabs(d_arg - d_exp) < 1e-128;
Primiano Tucci919ca1e2019-08-21 20:26:58 +020095}
Eric Secklerc36f22e2019-10-28 10:08:12 +000096} // namespace
Primiano Tucci919ca1e2019-08-21 20:26:58 +020097
Eric Secklerd3795132019-10-21 16:43:10 +010098class MockSchedEventTracker : public SchedEventTracker {
99 public:
100 MockSchedEventTracker(TraceProcessorContext* context)
101 : SchedEventTracker(context) {}
Eric Secklerd3795132019-10-21 16:43:10 +0100102
103 MOCK_METHOD9(PushSchedSwitch,
104 void(uint32_t cpu,
105 int64_t timestamp,
106 uint32_t prev_pid,
107 base::StringView prev_comm,
108 int32_t prev_prio,
109 int64_t prev_state,
110 uint32_t next_pid,
111 base::StringView next_comm,
112 int32_t next_prio));
113};
114
Isabelle Taylora97c5f52018-10-23 17:36:12 +0100115class MockEventTracker : public EventTracker {
Lalit Maganti35622b72018-06-06 12:03:11 +0100116 public:
Isabelle Taylora97c5f52018-10-23 17:36:12 +0100117 MockEventTracker(TraceProcessorContext* context) : EventTracker(context) {}
118 virtual ~MockEventTracker() = default;
Lalit Maganti35622b72018-06-06 12:03:11 +0100119
Lalit Magantibeb73712019-02-08 11:28:09 +0000120 MOCK_METHOD9(PushSchedSwitch,
Lalit Maganti35622b72018-06-06 12:03:11 +0100121 void(uint32_t cpu,
Lalit Maganti85ca4a82018-12-07 17:28:02 +0000122 int64_t timestamp,
Lalit Maganti35622b72018-06-06 12:03:11 +0100123 uint32_t prev_pid,
Lalit Magantibeb73712019-02-08 11:28:09 +0000124 base::StringView prev_comm,
125 int32_t prev_prio,
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000126 int64_t prev_state,
Lalit Magantifde29042018-10-04 13:28:52 +0100127 uint32_t next_pid,
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000128 base::StringView next_comm,
Lalit Magantibeb73712019-02-08 11:28:09 +0000129 int32_t next_prio));
Isabelle Taylor15314ea2018-09-19 11:35:19 +0100130
Lalit Maganti809b2f92019-11-07 13:27:26 +0000131 MOCK_METHOD3(PushCounter,
Lalit Magantib0e11f62020-01-02 14:17:58 +0000132 base::Optional<CounterId>(int64_t timestamp,
133 double value,
134 TrackId track_id));
Isabelle Taylora0a22972018-08-03 12:06:12 +0100135};
136
137class MockProcessTracker : public ProcessTracker {
138 public:
139 MockProcessTracker(TraceProcessorContext* context)
140 : ProcessTracker(context) {}
141
Lalit Maganti161d1e62019-06-25 16:06:17 +0100142 MOCK_METHOD3(SetProcessMetadata,
Lalit Maganti08884242019-02-19 12:28:32 +0000143 UniquePid(uint32_t pid,
144 base::Optional<uint32_t> ppid,
145 base::StringView process_name));
Isabelle Taylora0a22972018-08-03 12:06:12 +0100146
Siddhartha Sd37e5662019-06-13 18:27:42 -0700147 MOCK_METHOD2(UpdateThreadName,
148 UniqueTid(uint32_t tid, StringId thread_name_id));
Eric Seckler053ebaa2019-10-31 10:30:58 +0000149 MOCK_METHOD2(SetThreadNameIfUnset,
150 void(UniqueTid utid, StringId thread_name_id));
Isabelle Taylora0a22972018-08-03 12:06:12 +0100151 MOCK_METHOD2(UpdateThread, UniqueTid(uint32_t tid, uint32_t tgid));
Eric Secklera0366df2019-06-07 14:42:56 +0100152
153 MOCK_METHOD1(GetOrCreateProcess, UniquePid(uint32_t pid));
Eric Seckler7d128472020-01-13 10:03:51 +0000154 MOCK_METHOD2(SetProcessNameIfUnset,
155 void(UniquePid upid, StringId process_name_id));
Lalit Maganti35622b72018-06-06 12:03:11 +0100156};
157
Lalit Maganti7449dc82019-12-30 15:52:35 +0000158class MockBoundInserter : public ArgsTracker::BoundInserter {
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +0000159 public:
Lalit Maganti5228f362020-01-15 13:45:56 +0000160 MockBoundInserter() : ArgsTracker::BoundInserter(nullptr, nullptr, 0u) {
161 ON_CALL(*this, AddArg(_, _, _)).WillByDefault(ReturnRef(*this));
162 }
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +0000163
Lalit Maganti5228f362020-01-15 13:45:56 +0000164 MOCK_METHOD3(AddArg,
165 ArgsTracker::BoundInserter&(StringId flat_key,
166 StringId key,
167 Variadic v));
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +0000168};
169
Eric Seckler56a007d2019-05-02 16:25:14 +0100170class MockSliceTracker : public SliceTracker {
171 public:
172 MockSliceTracker(TraceProcessorContext* context) : SliceTracker(context) {}
173
Lalit Magantic7ea02e2019-12-12 14:06:49 +0000174 MOCK_METHOD5(Begin,
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100175 base::Optional<uint32_t>(int64_t timestamp,
Lalit Maganti21b21632019-09-28 16:50:23 +0100176 TrackId track_id,
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100177 StringId cat,
178 StringId name,
179 SetArgsCallback args_callback));
Lalit Maganti21b21632019-09-28 16:50:23 +0100180 MOCK_METHOD5(End,
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100181 base::Optional<uint32_t>(int64_t timestamp,
Lalit Maganti21b21632019-09-28 16:50:23 +0100182 TrackId track_id,
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100183 StringId cat,
184 StringId name,
185 SetArgsCallback args_callback));
Lalit Magantic7ea02e2019-12-12 14:06:49 +0000186 MOCK_METHOD6(Scoped,
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100187 base::Optional<uint32_t>(int64_t timestamp,
Lalit Maganti21b21632019-09-28 16:50:23 +0100188 TrackId track_id,
Lalit Maganti81a02cd2019-07-12 17:05:11 +0100189 StringId cat,
190 StringId name,
191 int64_t duration,
192 SetArgsCallback args_callback));
Eric Seckler56a007d2019-05-02 16:25:14 +0100193};
194
Primiano Tuccid933d912018-09-04 09:15:07 +0100195class ProtoTraceParserTest : public ::testing::Test {
196 public:
197 ProtoTraceParserTest() {
Lalit Maganti47bc3d62020-01-15 16:21:22 +0000198 storage_ = new TraceStorage();
Ryan Savitski0476ee92019-07-09 14:29:33 +0100199 context_.storage.reset(storage_);
Lalit Maganti4ea78d92019-09-20 20:20:41 +0100200 context_.track_tracker.reset(new TrackTracker(&context_));
Lalit Maganti1908e262020-01-09 14:33:19 +0000201 context_.global_args_tracker.reset(new GlobalArgsTracker(&context_));
Eric Secklerc93823e2019-06-03 16:49:19 +0100202 context_.args_tracker.reset(new ArgsTracker(&context_));
Lalit Magantiededb0e2020-01-08 12:50:34 +0000203 context_.metadata_tracker.reset(new MetadataTracker(&context_));
Isabelle Taylora97c5f52018-10-23 17:36:12 +0100204 event_ = new MockEventTracker(&context_);
205 context_.event_tracker.reset(event_);
Eric Secklerd3795132019-10-21 16:43:10 +0100206 sched_ = new MockSchedEventTracker(&context_);
207 context_.sched_tracker.reset(sched_);
Primiano Tuccid933d912018-09-04 09:15:07 +0100208 process_ = new MockProcessTracker(&context_);
209 context_.process_tracker.reset(process_);
Eric Seckler56a007d2019-05-02 16:25:14 +0100210 slice_ = new MockSliceTracker(&context_);
211 context_.slice_tracker.reset(slice_);
Eric Seckler15ea5df2019-10-14 13:54:07 +0100212 clock_ = new ClockTracker(&context_);
213 context_.clock_tracker.reset(clock_);
Primiano Tucci7de4ef22019-02-21 17:13:42 +0000214 context_.sorter.reset(new TraceSorter(&context_, 0 /*window size*/));
Deepanjan Roy01994ca2019-04-02 11:05:34 -0700215 context_.parser.reset(new ProtoTraceParser(&context_));
Mikhail Khokhlov4b5de1a2019-12-06 16:33:56 +0000216 context_.modules.emplace_back(new TrackEventModule(&context_));
Mikhail Khokhlov692087e2019-12-11 10:53:45 +0000217
218 RegisterAdditionalModules(&context_);
Primiano Tuccid933d912018-09-04 09:15:07 +0100219 }
Primiano Tucci7e330292018-08-24 19:10:52 +0200220
Primiano Tuccie5f11682019-03-22 07:21:49 +0000221 void ResetTraceBuffers() {
222 heap_buf_.reset(new protozero::ScatteredHeapBuffer());
223 stream_writer_.reset(new protozero::ScatteredStreamWriter(heap_buf_.get()));
224 heap_buf_->set_writer(stream_writer_.get());
225 trace_.Reset(stream_writer_.get());
226 }
227
228 void SetUp() override { ResetTraceBuffers(); }
229
Eric Seckler6f263fd2019-10-24 16:48:24 +0100230 util::Status Tokenize() {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000231 trace_.Finalize();
232 std::vector<uint8_t> trace_bytes = heap_buf_->StitchSlices();
233 std::unique_ptr<uint8_t[]> raw_trace(new uint8_t[trace_bytes.size()]);
234 memcpy(raw_trace.get(), trace_bytes.data(), trace_bytes.size());
Eric Seckler56a007d2019-05-02 16:25:14 +0100235 context_.chunk_reader.reset(new ProtoTraceTokenizer(&context_));
Eric Seckler6f263fd2019-10-24 16:48:24 +0100236 auto status =
237 context_.chunk_reader->Parse(std::move(raw_trace), trace_bytes.size());
Primiano Tuccie5f11682019-03-22 07:21:49 +0000238
239 ResetTraceBuffers();
Eric Seckler6f263fd2019-10-24 16:48:24 +0100240 return status;
Primiano Tuccid933d912018-09-04 09:15:07 +0100241 }
242
Eric Secklerb7e26332019-07-19 12:46:17 +0100243 bool HasArg(ArgSetId set_id, StringId key_id, Variadic value) {
Lalit Maganti1908e262020-01-09 14:33:19 +0000244 const auto& args = storage_->arg_table();
245 RowMap rm = args.FilterToRowMap({args.arg_set_id().eq(set_id)});
246 bool found = false;
247 for (auto it = rm.IterateRows(); it; it.Next()) {
248 if (args.key()[it.row()] == key_id) {
249 EXPECT_EQ(args.flat_key()[it.row()], key_id);
250 if (storage_->GetArgValue(it.row()) == value) {
251 found = true;
252 break;
Eric Secklerb7e26332019-07-19 12:46:17 +0100253 }
254 }
255 }
Lalit Maganti1908e262020-01-09 14:33:19 +0000256 return found;
Eric Secklerb7e26332019-07-19 12:46:17 +0100257 }
258
Primiano Tuccid933d912018-09-04 09:15:07 +0100259 protected:
Primiano Tuccie5f11682019-03-22 07:21:49 +0000260 std::unique_ptr<protozero::ScatteredHeapBuffer> heap_buf_;
261 std::unique_ptr<protozero::ScatteredStreamWriter> stream_writer_;
262 protos::pbzero::Trace trace_;
Primiano Tuccid933d912018-09-04 09:15:07 +0100263 TraceProcessorContext context_;
Isabelle Taylora97c5f52018-10-23 17:36:12 +0100264 MockEventTracker* event_;
Eric Secklerd3795132019-10-21 16:43:10 +0100265 MockSchedEventTracker* sched_;
Primiano Tuccid933d912018-09-04 09:15:07 +0100266 MockProcessTracker* process_;
Eric Seckler56a007d2019-05-02 16:25:14 +0100267 MockSliceTracker* slice_;
Eric Seckler15ea5df2019-10-14 13:54:07 +0100268 ClockTracker* clock_;
Lalit Maganti47bc3d62020-01-15 16:21:22 +0000269 TraceStorage* storage_;
Primiano Tuccid933d912018-09-04 09:15:07 +0100270};
271
Eric Seckler5c7866e2019-10-18 08:38:16 +0100272// TODO(eseckler): Refactor these into a new file for ftrace tests.
Eric Seckler5c7866e2019-10-18 08:38:16 +0100273
Primiano Tuccid933d912018-09-04 09:15:07 +0100274TEST_F(ProtoTraceParserTest, LoadSingleEvent) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000275 auto* bundle = trace_.add_packet()->set_ftrace_events();
Lalit Magantidf3e9262018-06-04 17:45:00 +0100276 bundle->set_cpu(10);
277
278 auto* event = bundle->add_event();
279 event->set_timestamp(1000);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000280 event->set_pid(12);
Lalit Magantidf3e9262018-06-04 17:45:00 +0100281
Lalit Magantibeb73712019-02-08 11:28:09 +0000282 static const char kProc1Name[] = "proc1";
283 static const char kProc2Name[] = "proc2";
Primiano Tuccie5f11682019-03-22 07:21:49 +0000284 auto* sched_switch = event->set_sched_switch();
Lalit Magantidf3e9262018-06-04 17:45:00 +0100285 sched_switch->set_prev_pid(10);
Lalit Magantibeb73712019-02-08 11:28:09 +0000286 sched_switch->set_prev_comm(kProc2Name);
287 sched_switch->set_prev_prio(256);
Lalit Maganti35622b72018-06-06 12:03:11 +0100288 sched_switch->set_prev_state(32);
Lalit Magantibeb73712019-02-08 11:28:09 +0000289 sched_switch->set_next_comm(kProc1Name);
Lalit Maganti35622b72018-06-06 12:03:11 +0100290 sched_switch->set_next_pid(100);
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000291 sched_switch->set_next_prio(1024);
Lalit Maganti35622b72018-06-06 12:03:11 +0100292
Eric Secklerd3795132019-10-21 16:43:10 +0100293 EXPECT_CALL(*sched_,
Lalit Magantibeb73712019-02-08 11:28:09 +0000294 PushSchedSwitch(10, 1000, 10, base::StringView(kProc2Name), 256,
295 32, 100, base::StringView(kProc1Name), 1024));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000296 Tokenize();
Lalit Maganti93b76362018-06-01 03:03:58 +0100297}
298
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +0000299TEST_F(ProtoTraceParserTest, LoadEventsIntoRaw) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000300 auto* bundle = trace_.add_packet()->set_ftrace_events();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000301 bundle->set_cpu(10);
302
303 // This event is unknown and will only appear in
304 // raw events table.
305 auto* event = bundle->add_event();
306 event->set_timestamp(1000);
307 event->set_pid(12);
Primiano Tuccie5f11682019-03-22 07:21:49 +0000308 auto* task = event->set_task_newtask();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000309 task->set_pid(123);
310 static const char task_newtask[] = "task_newtask";
311 task->set_comm(task_newtask);
312 task->set_clone_flags(12);
313 task->set_oom_score_adj(15);
314
315 // This event has specific parsing logic, but will
316 // also appear in raw events table.
317 event = bundle->add_event();
318 event->set_timestamp(1001);
319 event->set_pid(12);
Primiano Tuccie5f11682019-03-22 07:21:49 +0000320 auto* print = event->set_print();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000321 print->set_ip(20);
322 static const char buf_value[] = "This is a print event";
323 print->set_buf(buf_value);
324
Lalit Magantieac7fff2020-01-10 16:42:54 +0000325 EXPECT_CALL(*process_, GetOrCreateProcess(123));
Lalit Maganti1d915a62019-01-07 12:10:42 +0000326
Primiano Tuccie5f11682019-03-22 07:21:49 +0000327 Tokenize();
Ryan Savitski0476ee92019-07-09 14:29:33 +0100328
Lalit Maganti679b29d2020-01-13 13:26:28 +0000329 const auto& raw = context_.storage->raw_table();
330 ASSERT_EQ(raw.row_count(), 2u);
Lalit Maganti1908e262020-01-09 14:33:19 +0000331 const auto& args = context_.storage->arg_table();
332 ASSERT_EQ(args.row_count(), 6u);
333 ASSERT_EQ(args.int_value()[0], 123);
334 ASSERT_STREQ(context_.storage->GetString(args.string_value()[1]).c_str(),
335 task_newtask);
336 ASSERT_EQ(args.int_value()[2], 12);
337 ASSERT_EQ(args.int_value()[3], 15);
338 ASSERT_EQ(args.int_value()[4], 20);
339 ASSERT_STREQ(context_.storage->GetString(args.string_value()[5]).c_str(),
340 buf_value);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000341
342 // TODO(taylori): Add test ftrace event with all field types
343 // and test here.
344}
345
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +0000346TEST_F(ProtoTraceParserTest, LoadGenericFtrace) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000347 auto* packet = trace_.add_packet();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000348 packet->set_timestamp(100);
349
Primiano Tuccie5f11682019-03-22 07:21:49 +0000350 auto* bundle = packet->set_ftrace_events();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000351 bundle->set_cpu(4);
352
353 auto* ftrace = bundle->add_event();
354 ftrace->set_timestamp(100);
355 ftrace->set_pid(10);
356
Primiano Tuccie5f11682019-03-22 07:21:49 +0000357 auto* generic = ftrace->set_generic();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000358 generic->set_event_name("Test");
359
360 auto* field = generic->add_field();
361 field->set_name("meta1");
362 field->set_str_value("value1");
363
364 field = generic->add_field();
365 field->set_name("meta2");
366 field->set_int_value(-2);
367
368 field = generic->add_field();
369 field->set_name("meta3");
370 field->set_uint_value(3);
371
Primiano Tuccie5f11682019-03-22 07:21:49 +0000372 Tokenize();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000373
Lalit Maganti679b29d2020-01-13 13:26:28 +0000374 const auto& raw = storage_->raw_table();
Lalit Maganti1d915a62019-01-07 12:10:42 +0000375
Lalit Maganti679b29d2020-01-13 13:26:28 +0000376 ASSERT_EQ(raw.row_count(), 1u);
377 ASSERT_EQ(raw.ts()[raw.row_count() - 1], 100);
378 ASSERT_EQ(storage_->thread_table().tid()[raw.utid()[raw.row_count() - 1]],
379 10u);
Lalit Maganti47bc3d62020-01-15 16:21:22 +0000380 ASSERT_EQ(raw.name().GetString(raw.row_count() - 1), "Test");
Lalit Maganti4fa7c6c2019-02-06 15:06:36 +0000381
Lalit Maganti679b29d2020-01-13 13:26:28 +0000382 auto set_id = raw.arg_set_id()[raw.row_count() - 1];
Lalit Maganti1d915a62019-01-07 12:10:42 +0000383
Lalit Maganti1908e262020-01-09 14:33:19 +0000384 const auto& args = storage_->arg_table();
385 RowMap rm = args.FilterToRowMap({args.arg_set_id().eq(set_id)});
Lalit Maganti1d915a62019-01-07 12:10:42 +0000386
Lalit Maganti1908e262020-01-09 14:33:19 +0000387 auto row = rm.Get(0);
Lalit Maganti47bc3d62020-01-15 16:21:22 +0000388
389 ASSERT_EQ(args.key().GetString(row), "meta1");
390 ASSERT_EQ(args.string_value().GetString(row++), "value1");
391
392 ASSERT_EQ(args.key().GetString(row), "meta2");
393 ASSERT_EQ(args.int_value()[row++], -2);
394
395 ASSERT_EQ(args.key().GetString(row), "meta3");
396 ASSERT_EQ(args.int_value()[row++], 3);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000397}
398
Primiano Tuccid933d912018-09-04 09:15:07 +0100399TEST_F(ProtoTraceParserTest, LoadMultipleEvents) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000400 auto* bundle = trace_.add_packet()->set_ftrace_events();
Lalit Maganti35622b72018-06-06 12:03:11 +0100401 bundle->set_cpu(10);
402
403 auto* event = bundle->add_event();
404 event->set_timestamp(1000);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000405 event->set_pid(12);
Lalit Maganti35622b72018-06-06 12:03:11 +0100406
407 static const char kProcName1[] = "proc1";
Lalit Magantibeb73712019-02-08 11:28:09 +0000408 static const char kProcName2[] = "proc2";
Primiano Tuccie5f11682019-03-22 07:21:49 +0000409 auto* sched_switch = event->set_sched_switch();
Lalit Maganti35622b72018-06-06 12:03:11 +0100410 sched_switch->set_prev_pid(10);
Lalit Magantibeb73712019-02-08 11:28:09 +0000411 sched_switch->set_prev_comm(kProcName2);
412 sched_switch->set_prev_prio(256);
Lalit Maganti35622b72018-06-06 12:03:11 +0100413 sched_switch->set_prev_state(32);
Lalit Magantifde29042018-10-04 13:28:52 +0100414 sched_switch->set_next_comm(kProcName1);
Lalit Maganti35622b72018-06-06 12:03:11 +0100415 sched_switch->set_next_pid(100);
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000416 sched_switch->set_next_prio(1024);
Lalit Maganti35622b72018-06-06 12:03:11 +0100417
418 event = bundle->add_event();
419 event->set_timestamp(1001);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000420 event->set_pid(12);
Lalit Maganti35622b72018-06-06 12:03:11 +0100421
Primiano Tuccie5f11682019-03-22 07:21:49 +0000422 sched_switch = event->set_sched_switch();
Lalit Maganti35622b72018-06-06 12:03:11 +0100423 sched_switch->set_prev_pid(100);
Lalit Magantibeb73712019-02-08 11:28:09 +0000424 sched_switch->set_prev_comm(kProcName1);
425 sched_switch->set_prev_prio(256);
Lalit Maganti35622b72018-06-06 12:03:11 +0100426 sched_switch->set_prev_state(32);
Lalit Magantifde29042018-10-04 13:28:52 +0100427 sched_switch->set_next_comm(kProcName2);
Lalit Maganti35622b72018-06-06 12:03:11 +0100428 sched_switch->set_next_pid(10);
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000429 sched_switch->set_next_prio(512);
Lalit Maganti35622b72018-06-06 12:03:11 +0100430
Eric Secklerd3795132019-10-21 16:43:10 +0100431 EXPECT_CALL(*sched_,
Lalit Magantibeb73712019-02-08 11:28:09 +0000432 PushSchedSwitch(10, 1000, 10, base::StringView(kProcName2), 256,
433 32, 100, base::StringView(kProcName1), 1024));
Lalit Maganti35622b72018-06-06 12:03:11 +0100434
Eric Secklerd3795132019-10-21 16:43:10 +0100435 EXPECT_CALL(*sched_,
Lalit Magantibeb73712019-02-08 11:28:09 +0000436 PushSchedSwitch(10, 1001, 100, base::StringView(kProcName1), 256,
437 32, 10, base::StringView(kProcName2), 512));
Lalit Maganti35622b72018-06-06 12:03:11 +0100438
Primiano Tuccie5f11682019-03-22 07:21:49 +0000439 Tokenize();
Lalit Maganti35622b72018-06-06 12:03:11 +0100440}
441
Primiano Tuccid933d912018-09-04 09:15:07 +0100442TEST_F(ProtoTraceParserTest, LoadMultiplePackets) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000443 auto* bundle = trace_.add_packet()->set_ftrace_events();
Lalit Maganti35622b72018-06-06 12:03:11 +0100444 bundle->set_cpu(10);
445
446 auto* event = bundle->add_event();
447 event->set_timestamp(1000);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000448 event->set_pid(12);
Lalit Maganti35622b72018-06-06 12:03:11 +0100449
450 static const char kProcName1[] = "proc1";
Lalit Magantibeb73712019-02-08 11:28:09 +0000451 static const char kProcName2[] = "proc2";
Primiano Tuccie5f11682019-03-22 07:21:49 +0000452 auto* sched_switch = event->set_sched_switch();
Lalit Maganti35622b72018-06-06 12:03:11 +0100453 sched_switch->set_prev_pid(10);
Lalit Magantibeb73712019-02-08 11:28:09 +0000454 sched_switch->set_prev_comm(kProcName2);
455 sched_switch->set_prev_prio(256);
Lalit Maganti35622b72018-06-06 12:03:11 +0100456 sched_switch->set_prev_state(32);
Lalit Magantifde29042018-10-04 13:28:52 +0100457 sched_switch->set_next_comm(kProcName1);
Lalit Maganti35622b72018-06-06 12:03:11 +0100458 sched_switch->set_next_pid(100);
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000459 sched_switch->set_next_prio(1024);
Lalit Maganti35622b72018-06-06 12:03:11 +0100460
Primiano Tuccie5f11682019-03-22 07:21:49 +0000461 bundle = trace_.add_packet()->set_ftrace_events();
Lalit Maganti35622b72018-06-06 12:03:11 +0100462 bundle->set_cpu(10);
463
464 event = bundle->add_event();
465 event->set_timestamp(1001);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000466 event->set_pid(12);
Lalit Maganti35622b72018-06-06 12:03:11 +0100467
Primiano Tuccie5f11682019-03-22 07:21:49 +0000468 sched_switch = event->set_sched_switch();
Lalit Maganti35622b72018-06-06 12:03:11 +0100469 sched_switch->set_prev_pid(100);
Lalit Magantibeb73712019-02-08 11:28:09 +0000470 sched_switch->set_prev_comm(kProcName1);
471 sched_switch->set_prev_prio(256);
Lalit Maganti35622b72018-06-06 12:03:11 +0100472 sched_switch->set_prev_state(32);
Lalit Magantifde29042018-10-04 13:28:52 +0100473 sched_switch->set_next_comm(kProcName2);
Lalit Maganti35622b72018-06-06 12:03:11 +0100474 sched_switch->set_next_pid(10);
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000475 sched_switch->set_next_prio(512);
Lalit Maganti35622b72018-06-06 12:03:11 +0100476
Eric Secklerd3795132019-10-21 16:43:10 +0100477 EXPECT_CALL(*sched_,
Lalit Magantibeb73712019-02-08 11:28:09 +0000478 PushSchedSwitch(10, 1000, 10, base::StringView(kProcName2), 256,
479 32, 100, base::StringView(kProcName1), 1024));
Lalit Maganti35622b72018-06-06 12:03:11 +0100480
Eric Secklerd3795132019-10-21 16:43:10 +0100481 EXPECT_CALL(*sched_,
Lalit Magantibeb73712019-02-08 11:28:09 +0000482 PushSchedSwitch(10, 1001, 100, base::StringView(kProcName1), 256,
483 32, 10, base::StringView(kProcName2), 512));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000484 Tokenize();
Lalit Maganti93b76362018-06-01 03:03:58 +0100485}
486
Primiano Tuccid933d912018-09-04 09:15:07 +0100487TEST_F(ProtoTraceParserTest, RepeatedLoadSinglePacket) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000488 auto* bundle = trace_.add_packet()->set_ftrace_events();
Primiano Tuccid933d912018-09-04 09:15:07 +0100489 bundle->set_cpu(10);
490 auto* event = bundle->add_event();
491 event->set_timestamp(1000);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000492 event->set_pid(12);
Primiano Tuccid933d912018-09-04 09:15:07 +0100493 static const char kProcName1[] = "proc1";
Lalit Magantibeb73712019-02-08 11:28:09 +0000494 static const char kProcName2[] = "proc2";
Primiano Tuccie5f11682019-03-22 07:21:49 +0000495 auto* sched_switch = event->set_sched_switch();
Primiano Tuccid933d912018-09-04 09:15:07 +0100496 sched_switch->set_prev_pid(10);
Lalit Magantibeb73712019-02-08 11:28:09 +0000497 sched_switch->set_prev_comm(kProcName2);
498 sched_switch->set_prev_prio(256);
Primiano Tuccid933d912018-09-04 09:15:07 +0100499 sched_switch->set_prev_state(32);
Lalit Magantifde29042018-10-04 13:28:52 +0100500 sched_switch->set_next_comm(kProcName1);
Primiano Tuccid933d912018-09-04 09:15:07 +0100501 sched_switch->set_next_pid(100);
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000502 sched_switch->set_next_prio(1024);
Eric Secklerd3795132019-10-21 16:43:10 +0100503 EXPECT_CALL(*sched_,
Primiano Tuccie5f11682019-03-22 07:21:49 +0000504 PushSchedSwitch(10, 1000, 10, base::StringView(kProcName2), 256,
505 32, 100, base::StringView(kProcName1), 1024));
506 Tokenize();
Lalit Maganti35622b72018-06-06 12:03:11 +0100507
Primiano Tuccie5f11682019-03-22 07:21:49 +0000508 bundle = trace_.add_packet()->set_ftrace_events();
Primiano Tuccid933d912018-09-04 09:15:07 +0100509 bundle->set_cpu(10);
510 event = bundle->add_event();
511 event->set_timestamp(1001);
Lalit Maganti1d915a62019-01-07 12:10:42 +0000512 event->set_pid(12);
Primiano Tuccie5f11682019-03-22 07:21:49 +0000513 sched_switch = event->set_sched_switch();
Primiano Tuccid933d912018-09-04 09:15:07 +0100514 sched_switch->set_prev_pid(100);
Lalit Magantibeb73712019-02-08 11:28:09 +0000515 sched_switch->set_prev_comm(kProcName1);
516 sched_switch->set_prev_prio(256);
Primiano Tuccid933d912018-09-04 09:15:07 +0100517 sched_switch->set_prev_state(32);
Lalit Magantifde29042018-10-04 13:28:52 +0100518 sched_switch->set_next_comm(kProcName2);
Primiano Tuccid933d912018-09-04 09:15:07 +0100519 sched_switch->set_next_pid(10);
Lalit Maganti4af8dd82019-01-16 23:10:21 +0000520 sched_switch->set_next_prio(512);
Primiano Tuccid933d912018-09-04 09:15:07 +0100521
Eric Secklerd3795132019-10-21 16:43:10 +0100522 EXPECT_CALL(*sched_,
Lalit Magantibeb73712019-02-08 11:28:09 +0000523 PushSchedSwitch(10, 1001, 100, base::StringView(kProcName1), 256,
524 32, 10, base::StringView(kProcName2), 512));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000525 Tokenize();
Lalit Maganti93b76362018-06-01 03:03:58 +0100526}
527
Eric Seckler5c7866e2019-10-18 08:38:16 +0100528TEST_F(ProtoTraceParserTest, LoadCpuFreq) {
529 auto* bundle = trace_.add_packet()->set_ftrace_events();
530 bundle->set_cpu(12);
531 auto* event = bundle->add_event();
532 event->set_timestamp(1000);
533 event->set_pid(12);
534 auto* cpu_freq = event->set_cpu_frequency();
535 cpu_freq->set_cpu_id(10);
536 cpu_freq->set_state(2000);
537
Lalit Magantib0e11f62020-01-02 14:17:58 +0000538 EXPECT_CALL(*event_, PushCounter(1000, DoubleEq(2000), TrackId{0}));
Eric Seckler5c7866e2019-10-18 08:38:16 +0100539 Tokenize();
Lalit Maganti809b2f92019-11-07 13:27:26 +0000540
541 EXPECT_EQ(context_.storage->cpu_counter_track_table().cpu()[0], 10u);
Eric Seckler5c7866e2019-10-18 08:38:16 +0100542}
543
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100544TEST_F(ProtoTraceParserTest, LoadMemInfo) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000545 auto* packet = trace_.add_packet();
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100546 uint64_t ts = 1000;
547 packet->set_timestamp(ts);
Primiano Tuccie5f11682019-03-22 07:21:49 +0000548 auto* bundle = packet->set_sys_stats();
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100549 auto* meminfo = bundle->add_meminfo();
Primiano Tuccie5f11682019-03-22 07:21:49 +0000550 meminfo->set_key(protos::pbzero::MEMINFO_MEM_TOTAL);
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100551 uint32_t value = 10;
552 meminfo->set_value(value);
553
Lalit Maganti809b2f92019-11-07 13:27:26 +0000554 EXPECT_CALL(*event_, PushCounter(static_cast<int64_t>(ts),
Lalit Magantib0e11f62020-01-02 14:17:58 +0000555 DoubleEq(value * 1024.0), TrackId{0u}));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000556 Tokenize();
Lalit Maganti809b2f92019-11-07 13:27:26 +0000557
Lalit Maganti7e24f062019-12-17 18:10:35 +0000558 EXPECT_EQ(context_.storage->track_table().row_count(), 1u);
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100559}
560
561TEST_F(ProtoTraceParserTest, LoadVmStats) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000562 auto* packet = trace_.add_packet();
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100563 uint64_t ts = 1000;
564 packet->set_timestamp(ts);
Primiano Tuccie5f11682019-03-22 07:21:49 +0000565 auto* bundle = packet->set_sys_stats();
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100566 auto* meminfo = bundle->add_vmstat();
Primiano Tuccie5f11682019-03-22 07:21:49 +0000567 meminfo->set_key(protos::pbzero::VMSTAT_COMPACT_SUCCESS);
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100568 uint32_t value = 10;
569 meminfo->set_value(value);
570
Lalit Magantib0e11f62020-01-02 14:17:58 +0000571 EXPECT_CALL(*event_, PushCounter(static_cast<int64_t>(ts), DoubleEq(value),
572 TrackId{0u}));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000573 Tokenize();
Lalit Maganti809b2f92019-11-07 13:27:26 +0000574
Lalit Maganti7e24f062019-12-17 18:10:35 +0000575 EXPECT_EQ(context_.storage->track_table().row_count(), 1u);
Isabelle Taylor54ce7052018-10-01 14:00:15 +0100576}
577
Primiano Tuccid933d912018-09-04 09:15:07 +0100578TEST_F(ProtoTraceParserTest, LoadProcessPacket) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000579 auto* tree = trace_.add_packet()->set_process_tree();
Isabelle Taylord80932a2018-06-19 17:00:47 +0100580 auto* process = tree->add_processes();
581 static const char kProcName1[] = "proc1";
582
583 process->add_cmdline(kProcName1);
584 process->set_pid(1);
Lalit Magantib4274aa2019-07-09 14:29:48 +0100585 process->set_ppid(3);
Isabelle Taylord80932a2018-06-19 17:00:47 +0100586
Lalit Maganti08884242019-02-19 12:28:32 +0000587 EXPECT_CALL(*process_,
Lalit Magantib4274aa2019-07-09 14:29:48 +0100588 SetProcessMetadata(1, Eq(3u), base::StringView(kProcName1)));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000589 Tokenize();
Isabelle Taylord80932a2018-06-19 17:00:47 +0100590}
591
Primiano Tuccid933d912018-09-04 09:15:07 +0100592TEST_F(ProtoTraceParserTest, LoadProcessPacket_FirstCmdline) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000593 auto* tree = trace_.add_packet()->set_process_tree();
Isabelle Taylord80932a2018-06-19 17:00:47 +0100594 auto* process = tree->add_processes();
595 static const char kProcName1[] = "proc1";
596 static const char kProcName2[] = "proc2";
597
598 process->add_cmdline(kProcName1);
599 process->add_cmdline(kProcName2);
600 process->set_pid(1);
Lalit Magantib4274aa2019-07-09 14:29:48 +0100601 process->set_ppid(3);
Isabelle Taylord80932a2018-06-19 17:00:47 +0100602
Lalit Maganti08884242019-02-19 12:28:32 +0000603 EXPECT_CALL(*process_,
Lalit Magantib4274aa2019-07-09 14:29:48 +0100604 SetProcessMetadata(1, Eq(3u), base::StringView(kProcName1)));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000605 Tokenize();
Isabelle Taylord80932a2018-06-19 17:00:47 +0100606}
607
Primiano Tuccid933d912018-09-04 09:15:07 +0100608TEST_F(ProtoTraceParserTest, LoadThreadPacket) {
Primiano Tuccie5f11682019-03-22 07:21:49 +0000609 auto* tree = trace_.add_packet()->set_process_tree();
Isabelle Taylor3dd366c2018-06-22 16:21:41 +0100610 auto* thread = tree->add_threads();
611 thread->set_tid(1);
612 thread->set_tgid(2);
613
Primiano Tuccid933d912018-09-04 09:15:07 +0100614 EXPECT_CALL(*process_, UpdateThread(1, 2));
Primiano Tuccie5f11682019-03-22 07:21:49 +0000615 Tokenize();
Isabelle Taylor3dd366c2018-06-22 16:21:41 +0100616}
617
Eric Seckler7d128472020-01-13 10:03:51 +0000618TEST_F(ProtoTraceParserTest, ProcessNameFromProcessDescriptor) {
619 context_.sorter.reset(new TraceSorter(
620 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
621 {
622 auto* packet = trace_.add_packet();
623 packet->set_trusted_packet_sequence_id(1);
624 packet->set_incremental_state_cleared(true);
625 auto* process_desc = packet->set_process_descriptor();
626 process_desc->set_pid(15);
627 process_desc->set_process_name("OldProcessName");
628 }
629 {
630 auto* packet = trace_.add_packet();
631 packet->set_trusted_packet_sequence_id(1);
632 packet->set_incremental_state_cleared(true);
633 auto* process_desc = packet->set_process_descriptor();
634 process_desc->set_pid(15);
635 process_desc->set_process_name("NewProcessName");
636 }
637 {
638 auto* packet = trace_.add_packet();
639 packet->set_trusted_packet_sequence_id(2);
640 packet->set_incremental_state_cleared(true);
641 auto* process_desc = packet->set_process_descriptor();
642 process_desc->set_pid(16);
643 process_desc->set_process_name("DifferentProcessName");
644 }
645
646 EXPECT_CALL(*process_, GetOrCreateProcess(15))
647 .WillRepeatedly(testing::Return(1u));
648 EXPECT_CALL(*process_, GetOrCreateProcess(16)).WillOnce(testing::Return(2u));
649
Lalit Maganti47bc3d62020-01-15 16:21:22 +0000650 EXPECT_CALL(*process_, SetProcessNameIfUnset(
651 1u, storage_->InternString("OldProcessName")));
Eric Seckler7d128472020-01-13 10:03:51 +0000652 // Packet with same thread, but different name should update the name.
Lalit Maganti47bc3d62020-01-15 16:21:22 +0000653 EXPECT_CALL(*process_, SetProcessNameIfUnset(
654 1u, storage_->InternString("NewProcessName")));
655 EXPECT_CALL(*process_,
656 SetProcessNameIfUnset(
657 2u, storage_->InternString("DifferentProcessName")));
Eric Seckler7d128472020-01-13 10:03:51 +0000658
659 Tokenize();
660 context_.sorter->ExtractEventsForced();
661}
662
Siddhartha Sd37e5662019-06-13 18:27:42 -0700663TEST_F(ProtoTraceParserTest, ThreadNameFromThreadDescriptor) {
Siddhartha Sd37e5662019-06-13 18:27:42 -0700664 context_.sorter.reset(new TraceSorter(
665 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
666 {
667 auto* packet = trace_.add_packet();
668 packet->set_trusted_packet_sequence_id(1);
669 packet->set_incremental_state_cleared(true);
670 auto* thread_desc = packet->set_thread_descriptor();
671 thread_desc->set_pid(15);
672 thread_desc->set_tid(16);
673 thread_desc->set_reference_timestamp_us(1000);
674 thread_desc->set_reference_thread_time_us(2000);
675 thread_desc->set_thread_name("OldThreadName");
676 }
677 {
678 auto* packet = trace_.add_packet();
679 packet->set_trusted_packet_sequence_id(1);
680 packet->set_incremental_state_cleared(true);
681 auto* thread_desc = packet->set_thread_descriptor();
682 thread_desc->set_pid(15);
683 thread_desc->set_tid(16);
684 thread_desc->set_reference_timestamp_us(1000);
685 thread_desc->set_reference_thread_time_us(2000);
686 thread_desc->set_thread_name("NewThreadName");
687 }
688 {
689 auto* packet = trace_.add_packet();
690 packet->set_trusted_packet_sequence_id(2);
691 packet->set_incremental_state_cleared(true);
692 auto* thread_desc = packet->set_thread_descriptor();
693 thread_desc->set_pid(15);
694 thread_desc->set_tid(11);
695 thread_desc->set_reference_timestamp_us(1000);
696 thread_desc->set_reference_thread_time_us(2000);
697 thread_desc->set_thread_name("DifferentThreadName");
698 }
699
Eric Seckler9d48adc2019-10-24 16:57:15 +0100700 EXPECT_CALL(*process_, UpdateThread(16, 15))
701 .WillRepeatedly(testing::Return(1u));
702 EXPECT_CALL(*process_, UpdateThread(11, 15)).WillOnce(testing::Return(2u));
Siddhartha Sd37e5662019-06-13 18:27:42 -0700703
Lalit Maganti47bc3d62020-01-15 16:21:22 +0000704 EXPECT_CALL(*process_, SetThreadNameIfUnset(
705 1u, storage_->InternString("OldThreadName")));
Siddhartha Sd37e5662019-06-13 18:27:42 -0700706 // Packet with same thread, but different name should update the name.
Lalit Maganti47bc3d62020-01-15 16:21:22 +0000707 EXPECT_CALL(*process_, SetThreadNameIfUnset(
708 1u, storage_->InternString("NewThreadName")));
709 EXPECT_CALL(
710 *process_,
711 SetThreadNameIfUnset(2u, storage_->InternString("DifferentThreadName")));
Siddhartha Sd37e5662019-06-13 18:27:42 -0700712
713 Tokenize();
714 context_.sorter->ExtractEventsForced();
715}
716
Eric Seckler56a007d2019-05-02 16:25:14 +0100717TEST_F(ProtoTraceParserTest, TrackEventWithoutInternedData) {
Eric Seckler56a007d2019-05-02 16:25:14 +0100718 context_.sorter.reset(new TraceSorter(
719 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
720
721 {
722 auto* packet = trace_.add_packet();
723 packet->set_trusted_packet_sequence_id(1);
724 packet->set_incremental_state_cleared(true);
725 auto* thread_desc = packet->set_thread_descriptor();
726 thread_desc->set_pid(15);
727 thread_desc->set_tid(16);
728 thread_desc->set_reference_timestamp_us(1000);
729 thread_desc->set_reference_thread_time_us(2000);
730 }
731 {
732 auto* packet = trace_.add_packet();
733 packet->set_trusted_packet_sequence_id(1);
734 auto* event = packet->set_track_event();
735 event->set_timestamp_delta_us(10); // absolute: 1010.
736 event->set_thread_time_delta_us(5); // absolute: 2005.
737 event->add_category_iids(1);
738 auto* legacy_event = event->set_legacy_event();
739 legacy_event->set_name_iid(1);
740 legacy_event->set_phase('B');
741 }
742 {
743 auto* packet = trace_.add_packet();
744 packet->set_trusted_packet_sequence_id(1);
745 auto* event = packet->set_track_event();
746 event->set_timestamp_delta_us(10); // absolute: 1020.
747 event->set_thread_time_delta_us(5); // absolute: 2010.
748 event->add_category_iids(1);
749 auto* legacy_event = event->set_legacy_event();
750 legacy_event->set_name_iid(1);
751 legacy_event->set_phase('E');
752 }
753 {
754 auto* packet = trace_.add_packet();
755 packet->set_trusted_packet_sequence_id(1);
756 auto* event = packet->set_track_event();
757 event->set_timestamp_absolute_us(1005);
758 event->set_thread_time_absolute_us(2003);
759 event->add_category_iids(2);
760 event->add_category_iids(3);
761 auto* legacy_event = event->set_legacy_event();
762 legacy_event->set_name_iid(2);
763 legacy_event->set_phase('X');
764 legacy_event->set_duration_us(23); // absolute end: 1028.
765 legacy_event->set_thread_duration_us(12); // absolute end: 2015.
766 }
767
768 Tokenize();
769
770 EXPECT_CALL(*process_, UpdateThread(16, 15))
Eric Seckler56a007d2019-05-02 16:25:14 +0100771 .WillRepeatedly(Return(1));
772
Lalit Magantieac7fff2020-01-10 16:42:54 +0000773 tables::ThreadTable::Row row(16);
774 row.upid = 1u;
775 storage_->mutable_thread_table()->Insert(row);
Eric Secklerb32cacf2019-09-27 16:51:19 +0100776
Lalit Maganti7449dc82019-12-30 15:52:35 +0000777 MockBoundInserter inserter;
Eric Secklerd3b89d52019-07-10 15:36:29 +0100778
Lalit Magantib0e11f62020-01-02 14:17:58 +0000779 constexpr TrackId track{0u};
Eric Seckler56a007d2019-05-02 16:25:14 +0100780 InSequence in_sequence; // Below slices should be sorted by timestamp.
Lalit Magantic7ea02e2019-12-12 14:06:49 +0000781 EXPECT_CALL(*slice_,
782 Scoped(1005000, track, kNullStringId, kNullStringId, 23000, _))
Lalit Maganti7449dc82019-12-30 15:52:35 +0000783 .WillOnce(DoAll(InvokeArgument<5>(&inserter), Return(0u)));
Lalit Magantic7ea02e2019-12-12 14:06:49 +0000784 EXPECT_CALL(*slice_, Begin(1010000, track, kNullStringId, kNullStringId, _))
Lalit Maganti7449dc82019-12-30 15:52:35 +0000785 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(1u)));
Lalit Maganti21b21632019-09-28 16:50:23 +0100786 EXPECT_CALL(*slice_, End(1020000, track, kNullStringId, kNullStringId, _))
Lalit Maganti7449dc82019-12-30 15:52:35 +0000787 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(1u)));
Eric Seckler56a007d2019-05-02 16:25:14 +0100788
789 context_.sorter->ExtractEventsForced();
Eric Secklerd3b89d52019-07-10 15:36:29 +0100790
791 EXPECT_EQ(storage_->thread_slices().slice_count(), 2u);
792 EXPECT_EQ(storage_->thread_slices().slice_ids()[0], 0u);
793 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[0], 2003000);
794 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[0], 12000);
795 EXPECT_EQ(storage_->thread_slices().slice_ids()[1], 1u);
796 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[1], 2005000);
797 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[1], 5000);
Eric Seckler56a007d2019-05-02 16:25:14 +0100798}
799
Eric Seckler58fcbf12019-08-07 15:05:43 +0100800TEST_F(ProtoTraceParserTest, TrackEventWithoutInternedDataWithTypes) {
801 context_.sorter.reset(new TraceSorter(
802 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
803
804 {
805 auto* packet = trace_.add_packet();
806 packet->set_trusted_packet_sequence_id(1);
807 packet->set_incremental_state_cleared(true);
808 auto* thread_desc = packet->set_thread_descriptor();
809 thread_desc->set_pid(15);
810 thread_desc->set_tid(16);
811 thread_desc->set_reference_timestamp_us(1000);
812 thread_desc->set_reference_thread_time_us(2000);
813 }
814 {
815 auto* packet = trace_.add_packet();
816 packet->set_trusted_packet_sequence_id(1);
817 auto* event = packet->set_track_event();
818 event->set_timestamp_delta_us(10); // absolute: 1010.
819 event->set_thread_time_delta_us(5); // absolute: 2005.
820 event->add_category_iids(1);
821 event->set_type(protos::pbzero::TrackEvent::TYPE_SLICE_BEGIN);
822 auto* legacy_event = event->set_legacy_event();
823 legacy_event->set_name_iid(1);
824 }
825 {
826 auto* packet = trace_.add_packet();
827 packet->set_trusted_packet_sequence_id(1);
828 auto* event = packet->set_track_event();
829 event->set_timestamp_delta_us(10); // absolute: 1020.
830 event->set_thread_time_delta_us(5); // absolute: 2010.
831 event->add_category_iids(1);
832 event->set_type(protos::pbzero::TrackEvent::TYPE_SLICE_END);
833 auto* legacy_event = event->set_legacy_event();
834 legacy_event->set_name_iid(1);
835 }
Eric Seckler361c10e2019-08-13 11:40:13 +0100836 {
837 auto* packet = trace_.add_packet();
838 packet->set_trusted_packet_sequence_id(1);
839 auto* event = packet->set_track_event();
840 event->set_timestamp_absolute_us(1015);
841 event->set_thread_time_absolute_us(2007);
842 event->add_category_iids(2);
843 event->set_type(protos::pbzero::TrackEvent::TYPE_INSTANT);
844 auto* legacy_event = event->set_legacy_event();
845 legacy_event->set_name_iid(2);
846 }
Eric Seckler58fcbf12019-08-07 15:05:43 +0100847
848 Tokenize();
849
850 EXPECT_CALL(*process_, UpdateThread(16, 15))
Eric Seckler58fcbf12019-08-07 15:05:43 +0100851 .WillRepeatedly(Return(1));
852
Lalit Magantieac7fff2020-01-10 16:42:54 +0000853 tables::ThreadTable::Row row(16);
854 row.upid = 1u;
855 storage_->mutable_thread_table()->Insert(row);
Eric Secklerb32cacf2019-09-27 16:51:19 +0100856
Lalit Maganti7449dc82019-12-30 15:52:35 +0000857 MockBoundInserter inserter;
Eric Seckler58fcbf12019-08-07 15:05:43 +0100858
Lalit Magantib0e11f62020-01-02 14:17:58 +0000859 constexpr TrackId track{0u};
Eric Seckler58fcbf12019-08-07 15:05:43 +0100860 InSequence in_sequence; // Below slices should be sorted by timestamp.
Lalit Magantic7ea02e2019-12-12 14:06:49 +0000861 EXPECT_CALL(*slice_, Begin(1010000, track, kNullStringId, kNullStringId, _))
Lalit Maganti7449dc82019-12-30 15:52:35 +0000862 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(0u)));
Lalit Magantic7ea02e2019-12-12 14:06:49 +0000863 EXPECT_CALL(*slice_,
864 Scoped(1015000, track, kNullStringId, kNullStringId, 0, _))
Lalit Maganti7449dc82019-12-30 15:52:35 +0000865 .WillOnce(DoAll(InvokeArgument<5>(&inserter), Return(1u)));
Lalit Maganti21b21632019-09-28 16:50:23 +0100866 EXPECT_CALL(*slice_, End(1020000, track, kNullStringId, kNullStringId, _))
Lalit Maganti7449dc82019-12-30 15:52:35 +0000867 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(0u)));
Eric Seckler58fcbf12019-08-07 15:05:43 +0100868
869 context_.sorter->ExtractEventsForced();
870
Eric Seckler361c10e2019-08-13 11:40:13 +0100871 EXPECT_EQ(storage_->thread_slices().slice_count(), 2u);
Eric Seckler58fcbf12019-08-07 15:05:43 +0100872 EXPECT_EQ(storage_->thread_slices().slice_ids()[0], 0u);
873 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[0], 2005000);
874 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[0], 5000);
Eric Seckler361c10e2019-08-13 11:40:13 +0100875 EXPECT_EQ(storage_->thread_slices().slice_ids()[1], 1u);
876 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[1], 2007000);
877 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[1], 0);
Eric Seckler58fcbf12019-08-07 15:05:43 +0100878}
879
Eric Seckler56a007d2019-05-02 16:25:14 +0100880TEST_F(ProtoTraceParserTest, TrackEventWithInternedData) {
Eric Seckler56a007d2019-05-02 16:25:14 +0100881 context_.sorter.reset(new TraceSorter(
882 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
883
884 {
885 auto* packet = trace_.add_packet();
886 packet->set_trusted_packet_sequence_id(1);
887 packet->set_incremental_state_cleared(true);
888 auto* thread_desc = packet->set_thread_descriptor();
889 thread_desc->set_pid(15);
890 thread_desc->set_tid(16);
891 thread_desc->set_reference_timestamp_us(1000);
892 thread_desc->set_reference_thread_time_us(2000);
Eric Seckler54f30a32019-07-19 15:10:29 +0100893 thread_desc->set_reference_thread_instruction_count(3000);
Eric Seckler56a007d2019-05-02 16:25:14 +0100894 }
895 {
896 auto* packet = trace_.add_packet();
897 packet->set_trusted_packet_sequence_id(1);
898 auto* event = packet->set_track_event();
Eric Seckler54f30a32019-07-19 15:10:29 +0100899 event->set_timestamp_delta_us(10); // absolute: 1010.
900 event->set_thread_time_delta_us(5); // absolute: 2005.
901 event->set_thread_instruction_count_delta(20); // absolute: 3020.
Eric Seckler56a007d2019-05-02 16:25:14 +0100902 event->add_category_iids(1);
903 auto* legacy_event = event->set_legacy_event();
904 legacy_event->set_name_iid(1);
905 legacy_event->set_phase('B');
906
907 auto* interned_data = packet->set_interned_data();
908 auto cat1 = interned_data->add_event_categories();
909 cat1->set_iid(1);
910 cat1->set_name("cat1");
Eric Seckler0c460ef2019-08-14 15:42:36 +0100911 auto ev1 = interned_data->add_event_names();
Eric Seckler56a007d2019-05-02 16:25:14 +0100912 ev1->set_iid(1);
913 ev1->set_name("ev1");
914 }
915 {
916 auto* packet = trace_.add_packet();
917 packet->set_trusted_packet_sequence_id(1);
918 auto* event = packet->set_track_event();
Eric Seckler651ca312019-06-05 16:41:51 +0100919 event->set_timestamp_absolute_us(1040);
920 event->set_thread_time_absolute_us(2030);
Eric Seckler54f30a32019-07-19 15:10:29 +0100921 event->set_thread_instruction_count_absolute(3100);
Eric Seckler651ca312019-06-05 16:41:51 +0100922 event->add_category_iids(1);
923 auto* legacy_event = event->set_legacy_event();
924 legacy_event->set_name_iid(1);
925 legacy_event->set_phase('I');
926 }
927 {
928 auto* packet = trace_.add_packet();
929 packet->set_trusted_packet_sequence_id(1);
930 auto* event = packet->set_track_event();
Eric Secklera0366df2019-06-07 14:42:56 +0100931 event->set_timestamp_absolute_us(1050);
932 event->add_category_iids(1);
933 auto* legacy_event = event->set_legacy_event();
934 legacy_event->set_name_iid(1);
935 legacy_event->set_phase('i');
936 legacy_event->set_instant_event_scope(
937 protos::pbzero::TrackEvent::LegacyEvent::SCOPE_PROCESS);
938 }
939 {
940 auto* packet = trace_.add_packet();
941 packet->set_trusted_packet_sequence_id(1);
942 auto* event = packet->set_track_event();
Eric Seckler54f30a32019-07-19 15:10:29 +0100943 event->set_timestamp_delta_us(10); // absolute: 1020.
944 event->set_thread_time_delta_us(5); // absolute: 2010.
945 event->set_thread_instruction_count_delta(20); // absolute: 3040.
Eric Seckler56a007d2019-05-02 16:25:14 +0100946 event->add_category_iids(1);
947 auto* legacy_event = event->set_legacy_event();
948 legacy_event->set_name_iid(1);
949 legacy_event->set_phase('E');
950 }
951 {
952 auto* packet = trace_.add_packet();
953 packet->set_trusted_packet_sequence_id(1);
954 auto* event = packet->set_track_event();
955 event->set_timestamp_absolute_us(1005);
956 event->set_thread_time_absolute_us(2003);
Eric Seckler54f30a32019-07-19 15:10:29 +0100957 event->set_thread_instruction_count_absolute(3010);
Eric Seckler56a007d2019-05-02 16:25:14 +0100958 event->add_category_iids(2);
959 event->add_category_iids(3);
960 auto* legacy_event = event->set_legacy_event();
Eric Seckler624e60f2019-10-14 20:57:50 +0100961 legacy_event->set_name_iid(4);
Eric Seckler56a007d2019-05-02 16:25:14 +0100962 legacy_event->set_phase('X');
Eric Seckler54f30a32019-07-19 15:10:29 +0100963 legacy_event->set_duration_us(23); // absolute end: 1028.
964 legacy_event->set_thread_duration_us(12); // absolute end: 2015.
965 legacy_event->set_thread_instruction_delta(50); // absolute end: 3060.
Eric Seckler6f13e332019-10-15 12:14:04 +0100966 legacy_event->set_bind_id(9999);
967 legacy_event->set_bind_to_enclosing(true);
968 legacy_event->set_flow_direction(
969 protos::pbzero::TrackEvent::LegacyEvent::FLOW_INOUT);
Eric Seckler56a007d2019-05-02 16:25:14 +0100970
971 auto* interned_data = packet->set_interned_data();
972 auto cat2 = interned_data->add_event_categories();
973 cat2->set_iid(2);
974 cat2->set_name("cat2");
975 auto cat3 = interned_data->add_event_categories();
976 cat3->set_iid(3);
977 cat3->set_name("cat3");
Eric Seckler0c460ef2019-08-14 15:42:36 +0100978 auto ev2 = interned_data->add_event_names();
Eric Seckler624e60f2019-10-14 20:57:50 +0100979 ev2->set_iid(4);
Eric Seckler56a007d2019-05-02 16:25:14 +0100980 ev2->set_name("ev2");
981 }
982
983 Tokenize();
984
985 EXPECT_CALL(*process_, UpdateThread(16, 15))
Eric Seckler56a007d2019-05-02 16:25:14 +0100986 .WillRepeatedly(Return(1));
987
Lalit Magantieac7fff2020-01-10 16:42:54 +0000988 tables::ThreadTable::Row row(16);
989 row.upid = 2u;
990 storage_->mutable_thread_table()->Insert(row);
Eric Secklera0366df2019-06-07 14:42:56 +0100991
Lalit Magantib0e11f62020-01-02 14:17:58 +0000992 constexpr TrackId thread_1_track{0u};
993 constexpr TrackId process_2_track{1u};
Lalit Maganti21b21632019-09-28 16:50:23 +0100994
Lalit Maganti47bc3d62020-01-15 16:21:22 +0000995 StringId cat_2_3 = storage_->InternString("cat2,cat3");
996 StringId ev_2 = storage_->InternString("ev2");
997 StringId cat_1 = storage_->InternString("cat1");
998 StringId ev_1 = storage_->InternString("ev1");
Eric Seckler02cdcef2019-10-14 08:56:28 +0100999
1000 InSequence in_sequence; // Below slices should be sorted by timestamp.
1001
Lalit Maganti7449dc82019-12-30 15:52:35 +00001002 MockBoundInserter inserter;
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001003 EXPECT_CALL(*slice_, Scoped(1005000, thread_1_track, cat_2_3, ev_2, 23000, _))
Lalit Maganti7449dc82019-12-30 15:52:35 +00001004 .WillOnce(DoAll(InvokeArgument<5>(&inserter), Return(0u)));
1005 EXPECT_CALL(inserter, AddArg(_, _, Variadic::UnsignedInteger(9999u)));
1006 EXPECT_CALL(inserter, AddArg(_, _, Variadic::Boolean(true)));
1007 EXPECT_CALL(inserter, AddArg(_, _, _));
Eric Seckler56a007d2019-05-02 16:25:14 +01001008
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001009 EXPECT_CALL(*slice_, Begin(1010000, thread_1_track, cat_1, ev_1, _))
Lalit Maganti7449dc82019-12-30 15:52:35 +00001010 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(1u)));
Lalit Maganti21b21632019-09-28 16:50:23 +01001011
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001012 EXPECT_CALL(*slice_, End(1020000, thread_1_track, cat_1, ev_1, _))
Lalit Maganti7449dc82019-12-30 15:52:35 +00001013 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(1u)));
Lalit Maganti21b21632019-09-28 16:50:23 +01001014
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001015 EXPECT_CALL(*slice_, Scoped(1040000, thread_1_track, cat_1, ev_1, 0, _))
Lalit Maganti7449dc82019-12-30 15:52:35 +00001016 .WillOnce(DoAll(InvokeArgument<5>(&inserter), Return(2u)));
Eric Secklera0366df2019-06-07 14:42:56 +01001017
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001018 EXPECT_CALL(*slice_, Scoped(1050000, process_2_track, cat_1, ev_1, 0, _))
Lalit Maganti7449dc82019-12-30 15:52:35 +00001019 .WillOnce(DoAll(InvokeArgument<5>(&inserter), Return(3u)));
Eric Secklerbb0e1542020-01-16 13:44:13 +00001020 // Second slice should have a legacy_event.passthrough_utid arg.
1021 EXPECT_CALL(inserter, AddArg(_, _, Variadic::UnsignedInteger(1u)));
Eric Seckler87fd11a2019-06-07 15:52:28 +01001022
1023 context_.sorter->ExtractEventsForced();
Eric Secklerd3b89d52019-07-10 15:36:29 +01001024
1025 EXPECT_EQ(storage_->thread_slices().slice_count(), 3u);
1026 EXPECT_EQ(storage_->thread_slices().slice_ids()[0], 0u);
1027 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[0], 2003000);
1028 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[0], 12000);
Eric Seckler54f30a32019-07-19 15:10:29 +01001029 EXPECT_EQ(storage_->thread_slices().thread_instruction_counts()[0], 3010);
1030 EXPECT_EQ(storage_->thread_slices().thread_instruction_deltas()[0], 50);
Eric Secklerd3b89d52019-07-10 15:36:29 +01001031 EXPECT_EQ(storage_->thread_slices().slice_ids()[1], 1u);
1032 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[1], 2005000);
1033 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[1], 5000);
Eric Seckler54f30a32019-07-19 15:10:29 +01001034 EXPECT_EQ(storage_->thread_slices().thread_instruction_counts()[1], 3020);
1035 EXPECT_EQ(storage_->thread_slices().thread_instruction_deltas()[1], 20);
Eric Secklerd3b89d52019-07-10 15:36:29 +01001036 EXPECT_EQ(storage_->thread_slices().slice_ids()[2], 2u);
1037 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[2], 2030000);
1038 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[2], 0);
Eric Seckler54f30a32019-07-19 15:10:29 +01001039 EXPECT_EQ(storage_->thread_slices().thread_instruction_counts()[2], 3100);
1040 EXPECT_EQ(storage_->thread_slices().thread_instruction_deltas()[2], 0);
Eric Seckler87fd11a2019-06-07 15:52:28 +01001041}
1042
1043TEST_F(ProtoTraceParserTest, TrackEventAsyncEvents) {
Eric Seckler87fd11a2019-06-07 15:52:28 +01001044 context_.sorter.reset(new TraceSorter(
1045 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
1046
1047 {
1048 auto* packet = trace_.add_packet();
1049 packet->set_trusted_packet_sequence_id(1);
1050 packet->set_incremental_state_cleared(true);
1051 auto* thread_desc = packet->set_thread_descriptor();
1052 thread_desc->set_pid(15);
1053 thread_desc->set_tid(16);
1054 thread_desc->set_reference_timestamp_us(1000);
1055 thread_desc->set_reference_thread_time_us(2000);
Eric Seckler54f30a32019-07-19 15:10:29 +01001056 thread_desc->set_reference_thread_instruction_count(3000);
Eric Seckler87fd11a2019-06-07 15:52:28 +01001057 }
1058 {
1059 auto* packet = trace_.add_packet();
1060 packet->set_trusted_packet_sequence_id(1);
1061 auto* event = packet->set_track_event();
Eric Seckler54f30a32019-07-19 15:10:29 +01001062 event->set_timestamp_delta_us(10); // absolute: 1010.
1063 event->set_thread_time_delta_us(5); // absolute: 2005.
1064 event->set_thread_instruction_count_delta(20); // absolute: 3020.
Eric Seckler87fd11a2019-06-07 15:52:28 +01001065 event->add_category_iids(1);
1066 auto* legacy_event = event->set_legacy_event();
1067 legacy_event->set_name_iid(1);
1068 legacy_event->set_phase('b');
1069 legacy_event->set_global_id(10);
Eric Secklerc3430c62019-07-22 10:49:58 +01001070 legacy_event->set_use_async_tts(true);
Eric Seckler87fd11a2019-06-07 15:52:28 +01001071
1072 auto* interned_data = packet->set_interned_data();
1073 auto cat1 = interned_data->add_event_categories();
1074 cat1->set_iid(1);
1075 cat1->set_name("cat1");
Eric Seckler0c460ef2019-08-14 15:42:36 +01001076 auto ev1 = interned_data->add_event_names();
Eric Seckler87fd11a2019-06-07 15:52:28 +01001077 ev1->set_iid(1);
1078 ev1->set_name("ev1");
1079 }
1080 {
1081 auto* packet = trace_.add_packet();
1082 packet->set_trusted_packet_sequence_id(1);
1083 auto* event = packet->set_track_event();
Eric Seckler54f30a32019-07-19 15:10:29 +01001084 event->set_timestamp_delta_us(10); // absolute: 1020.
1085 event->set_thread_time_delta_us(5); // absolute: 2010.
1086 event->set_thread_instruction_count_delta(20); // absolute: 3040.
Eric Seckler87fd11a2019-06-07 15:52:28 +01001087 event->add_category_iids(1);
1088 auto* legacy_event = event->set_legacy_event();
1089 legacy_event->set_name_iid(1);
1090 legacy_event->set_phase('e');
1091 legacy_event->set_global_id(10);
Eric Secklerc3430c62019-07-22 10:49:58 +01001092 legacy_event->set_use_async_tts(true);
Eric Seckler87fd11a2019-06-07 15:52:28 +01001093 }
1094 {
1095 auto* packet = trace_.add_packet();
1096 packet->set_trusted_packet_sequence_id(1);
1097 auto* event = packet->set_track_event();
1098 event->set_timestamp_absolute_us(1015);
Eric Secklerebe76eb2019-10-16 14:49:12 +01001099 event->add_category_iids(1);
Eric Seckler87fd11a2019-06-07 15:52:28 +01001100 auto* legacy_event = event->set_legacy_event();
1101 legacy_event->set_name_iid(2);
1102 legacy_event->set_phase('n');
1103 legacy_event->set_global_id(10);
1104
1105 auto* interned_data = packet->set_interned_data();
Eric Seckler0c460ef2019-08-14 15:42:36 +01001106 auto ev2 = interned_data->add_event_names();
Eric Seckler87fd11a2019-06-07 15:52:28 +01001107 ev2->set_iid(2);
1108 ev2->set_name("ev2");
1109 }
1110 {
Eric Secklerebe76eb2019-10-16 14:49:12 +01001111 // Different category but same global_id -> separate track.
1112 auto* packet = trace_.add_packet();
1113 packet->set_trusted_packet_sequence_id(1);
1114 auto* event = packet->set_track_event();
1115 event->set_timestamp_absolute_us(1018);
1116 event->add_category_iids(2);
1117 auto* legacy_event = event->set_legacy_event();
1118 legacy_event->set_name_iid(2);
1119 legacy_event->set_phase('n');
1120 legacy_event->set_global_id(15);
1121
1122 auto* interned_data = packet->set_interned_data();
1123 auto cat2 = interned_data->add_event_categories();
1124 cat2->set_iid(2);
1125 cat2->set_name("cat2");
1126 }
1127 {
Eric Seckler87fd11a2019-06-07 15:52:28 +01001128 auto* packet = trace_.add_packet();
1129 packet->set_trusted_packet_sequence_id(1);
1130 auto* event = packet->set_track_event();
1131 event->set_timestamp_absolute_us(1030);
1132 event->add_category_iids(2);
1133 auto* legacy_event = event->set_legacy_event();
1134 legacy_event->set_name_iid(2);
1135 legacy_event->set_phase('n');
1136 legacy_event->set_local_id(15);
1137 legacy_event->set_id_scope("scope1");
1138 }
1139
1140 Tokenize();
1141
Eric Seckler137a4672019-10-24 08:51:14 +01001142 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillRepeatedly(Return(1));
Eric Secklerb32cacf2019-09-27 16:51:19 +01001143
Lalit Magantieac7fff2020-01-10 16:42:54 +00001144 tables::ThreadTable::Row row(16);
1145 row.upid = 1u;
1146 storage_->mutable_thread_table()->Insert(row);
Eric Seckler87fd11a2019-06-07 15:52:28 +01001147
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001148 StringId cat_1 = storage_->InternString("cat1");
1149 StringId ev_1 = storage_->InternString("ev1");
1150 StringId cat_2 = storage_->InternString("cat2");
1151 StringId ev_2 = storage_->InternString("ev2");
Eric Seckler02cdcef2019-10-14 08:56:28 +01001152
Eric Seckler87fd11a2019-06-07 15:52:28 +01001153 InSequence in_sequence; // Below slices should be sorted by timestamp.
1154
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001155 EXPECT_CALL(*slice_, Begin(1010000, TrackId{1}, cat_1, ev_1, _))
Eric Secklerc3430c62019-07-22 10:49:58 +01001156 .WillOnce(Return(0u));
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001157 EXPECT_CALL(*slice_, Scoped(1015000, TrackId{1}, cat_1, ev_2, 0, _));
1158 EXPECT_CALL(*slice_, Scoped(1018000, TrackId{2}, cat_2, ev_2, 0, _));
1159 EXPECT_CALL(*slice_, End(1020000, TrackId{1}, cat_1, ev_1, _))
Eric Secklerc3430c62019-07-22 10:49:58 +01001160 .WillOnce(Return(0u));
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001161 EXPECT_CALL(*slice_, Scoped(1030000, TrackId{3}, cat_2, ev_2, 0, _));
Eric Seckler651ca312019-06-05 16:41:51 +01001162
Eric Seckler56a007d2019-05-02 16:25:14 +01001163 context_.sorter->ExtractEventsForced();
Eric Seckler5703ede2019-07-10 10:13:02 +01001164
Eric Secklerebe76eb2019-10-16 14:49:12 +01001165 // First track is for the thread; others are the async event tracks.
Lalit Maganti7e24f062019-12-17 18:10:35 +00001166 EXPECT_EQ(storage_->track_table().row_count(), 4u);
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001167 EXPECT_EQ(storage_->track_table().name()[1], ev_1);
1168 EXPECT_EQ(storage_->track_table().name()[2], ev_2);
1169 EXPECT_EQ(storage_->track_table().name()[3], ev_2);
Lalit Maganti53bdbb22019-09-25 11:11:18 +01001170
Lalit Maganti7e24f062019-12-17 18:10:35 +00001171 EXPECT_EQ(storage_->process_track_table().row_count(), 3u);
Lalit Maganti53bdbb22019-09-25 11:11:18 +01001172 EXPECT_EQ(storage_->process_track_table().upid()[0], 1u);
Eric Secklerebe76eb2019-10-16 14:49:12 +01001173 EXPECT_EQ(storage_->process_track_table().upid()[1], 1u);
1174 EXPECT_EQ(storage_->process_track_table().upid()[2], 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);
Eric Seckler3183c6d2020-01-14 15:45:20 +00001196 packet->set_timestamp(1000000);
Eric Secklerb32cacf2019-09-27 16:51:19 +01001197 auto* track_desc = packet->set_track_descriptor();
1198 track_desc->set_uuid(1234);
1199 track_desc->set_name("Thread track 1");
1200 auto* thread_desc = track_desc->set_thread();
1201 thread_desc->set_pid(15);
1202 thread_desc->set_tid(16);
1203 }
1204 {
1205 auto* packet = trace_.add_packet();
1206 packet->set_trusted_packet_sequence_id(1);
Eric Seckler3183c6d2020-01-14 15:45:20 +00001207 packet->set_timestamp(1000000);
Eric Secklerb32cacf2019-09-27 16:51:19 +01001208 auto* track_desc = packet->set_track_descriptor();
1209 track_desc->set_uuid(5678);
1210 track_desc->set_name("Async track 1");
1211 }
1212 {
1213 // Async event started on "Async track 1".
1214 auto* packet = trace_.add_packet();
1215 packet->set_trusted_packet_sequence_id(1);
1216 packet->set_timestamp(1010000);
1217 auto* event = packet->set_track_event();
1218 event->set_track_uuid(5678);
1219 event->set_thread_time_absolute_us(2005);
1220 event->set_thread_instruction_count_absolute(3020);
1221 event->add_category_iids(1);
1222 event->set_name_iid(1);
1223 event->set_type(protos::pbzero::TrackEvent::TYPE_SLICE_BEGIN);
1224 auto* legacy_event = event->set_legacy_event();
1225 legacy_event->set_use_async_tts(true);
1226
1227 auto* interned_data = packet->set_interned_data();
1228 auto cat1 = interned_data->add_event_categories();
1229 cat1->set_iid(1);
1230 cat1->set_name("cat1");
1231 auto ev1 = interned_data->add_event_names();
1232 ev1->set_iid(1);
1233 ev1->set_name("ev1");
1234 }
1235 {
1236 // Instant event on "Thread track 1".
1237 auto* packet = trace_.add_packet();
1238 packet->set_trusted_packet_sequence_id(1);
1239 packet->set_timestamp(1015000);
1240 auto* event = packet->set_track_event();
1241 event->set_track_uuid(1234);
1242 event->set_thread_time_absolute_us(2007);
1243 event->add_category_iids(2);
1244 event->set_name_iid(2);
1245 event->set_type(protos::pbzero::TrackEvent::TYPE_INSTANT);
1246
1247 auto* interned_data = packet->set_interned_data();
1248 auto cat1 = interned_data->add_event_categories();
1249 cat1->set_iid(2);
1250 cat1->set_name("cat2");
1251 auto ev1 = interned_data->add_event_names();
1252 ev1->set_iid(2);
1253 ev1->set_name("ev2");
1254 }
1255
1256 // Sequence 2.
1257 {
1258 auto* packet = trace_.add_packet();
1259 packet->set_trusted_packet_sequence_id(2);
1260 packet->set_incremental_state_cleared(true);
Eric Seckler3183c6d2020-01-14 15:45:20 +00001261 packet->set_timestamp(1000000);
Eric Secklerb32cacf2019-09-27 16:51:19 +01001262 auto* track_desc = packet->set_track_descriptor();
1263 track_desc->set_uuid(4321);
1264 track_desc->set_name("Thread track 2");
1265 auto* thread_desc = track_desc->set_thread();
1266 thread_desc->set_pid(15);
1267 thread_desc->set_tid(17);
1268 }
1269 {
Eric Secklerb32cacf2019-09-27 16:51:19 +01001270 // Async event completed on "Async track 1".
1271 auto* packet = trace_.add_packet();
1272 packet->set_trusted_packet_sequence_id(2);
1273 packet->set_timestamp(1020000);
1274 auto* event = packet->set_track_event();
1275 event->set_track_uuid(5678);
1276 event->set_thread_time_absolute_us(2010);
1277 event->set_thread_instruction_count_absolute(3040);
1278 event->set_type(protos::pbzero::TrackEvent::TYPE_SLICE_END);
1279 auto* legacy_event = event->set_legacy_event();
1280 legacy_event->set_use_async_tts(true);
1281 }
1282 {
1283 // Instant event on "Thread track 2".
1284 auto* packet = trace_.add_packet();
1285 packet->set_trusted_packet_sequence_id(2);
1286 packet->set_timestamp(1016000);
1287 auto* event = packet->set_track_event();
1288 event->set_track_uuid(4321);
1289 event->set_thread_time_absolute_us(2008);
1290 event->add_category_iids(1);
1291 event->set_name_iid(1);
1292 event->set_type(protos::pbzero::TrackEvent::TYPE_INSTANT);
1293
1294 auto* interned_data = packet->set_interned_data();
1295 auto cat1 = interned_data->add_event_categories();
1296 cat1->set_iid(1);
1297 cat1->set_name("cat3");
1298 auto ev1 = interned_data->add_event_names();
1299 ev1->set_iid(1);
1300 ev1->set_name("ev3");
1301 }
1302
1303 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillRepeatedly(Return(1));
1304 EXPECT_CALL(*process_, UpdateThread(17, 15)).WillRepeatedly(Return(2));
1305
Lalit Magantieac7fff2020-01-10 16:42:54 +00001306 tables::ThreadTable::Row t1(16);
1307 t1.upid = 1u;
1308 storage_->mutable_thread_table()->Insert(t1);
1309
1310 tables::ThreadTable::Row t2(16);
1311 t2.upid = 2u;
1312 storage_->mutable_thread_table()->Insert(t2);
Eric Secklerb32cacf2019-09-27 16:51:19 +01001313
Eric Secklerb32cacf2019-09-27 16:51:19 +01001314 Tokenize();
1315
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001316 StringId cat_1 = storage_->InternString("cat1");
1317 StringId ev_1 = storage_->InternString("ev1");
1318 StringId cat_2 = storage_->InternString("cat2");
1319 StringId ev_2 = storage_->InternString("ev2");
1320 StringId cat_3 = storage_->InternString("cat3");
1321 StringId ev_3 = storage_->InternString("ev3");
1322
Eric Secklerb32cacf2019-09-27 16:51:19 +01001323 InSequence in_sequence; // Below slices should be sorted by timestamp.
1324
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001325 EXPECT_CALL(*slice_, Begin(1010000, TrackId{1}, cat_1, ev_1, _))
Eric Secklerb32cacf2019-09-27 16:51:19 +01001326 .WillOnce(Return(0u));
1327
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001328 EXPECT_CALL(*slice_, Scoped(1015000, TrackId{0}, cat_2, ev_2, 0, _))
Eric Secklerb32cacf2019-09-27 16:51:19 +01001329 .WillOnce(Return(1u));
1330
Eric Secklerc64e19c2020-01-28 15:47:56 +00001331 EXPECT_CALL(*slice_, Scoped(1016000, TrackId{3}, cat_3, ev_3, 0, _))
Eric Secklerb32cacf2019-09-27 16:51:19 +01001332 .WillOnce(Return(2u));
1333
Lalit Magantif0599a02020-01-15 15:45:20 +00001334 EXPECT_CALL(*slice_,
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001335 End(1020000, TrackId{1}, kNullStringId, kNullStringId, _))
Eric Secklerb32cacf2019-09-27 16:51:19 +01001336 .WillOnce(Return(0u));
1337
1338 context_.sorter->ExtractEventsForced();
1339
Eric Secklerc64e19c2020-01-28 15:47:56 +00001340 // First track is "Thread track 1"; second is "Async track 1", third is global
1341 // default track (parent of async track), fourth is "Thread track 2".
1342 EXPECT_EQ(storage_->track_table().row_count(), 4u);
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001343 EXPECT_EQ(storage_->track_table().name().GetString(0), "Thread track 1");
1344 EXPECT_EQ(storage_->track_table().name().GetString(1), "Async track 1");
Eric Secklerc64e19c2020-01-28 15:47:56 +00001345 EXPECT_EQ(storage_->track_table().name().GetString(2), "Default Track");
1346 EXPECT_EQ(storage_->track_table().name().GetString(3), "Thread track 2");
Lalit Maganti7e24f062019-12-17 18:10:35 +00001347 EXPECT_EQ(storage_->thread_track_table().row_count(), 2u);
Eric Seckler3183c6d2020-01-14 15:45:20 +00001348 EXPECT_EQ(storage_->thread_track_table().utid()[0], 1u);
1349 EXPECT_EQ(storage_->thread_track_table().utid()[1], 2u);
Eric Secklerb32cacf2019-09-27 16:51:19 +01001350
1351 EXPECT_EQ(storage_->virtual_track_slices().slice_count(), 1u);
1352 EXPECT_EQ(storage_->virtual_track_slices().slice_ids()[0], 0u);
1353 EXPECT_EQ(storage_->virtual_track_slices().thread_timestamp_ns()[0], 2005000);
1354 EXPECT_EQ(storage_->virtual_track_slices().thread_duration_ns()[0], 5000);
1355 EXPECT_EQ(storage_->virtual_track_slices().thread_instruction_counts()[0],
1356 3020);
1357 EXPECT_EQ(storage_->virtual_track_slices().thread_instruction_deltas()[0],
1358 20);
1359
1360 EXPECT_EQ(storage_->thread_slices().slice_count(), 2u);
1361 EXPECT_EQ(storage_->thread_slices().slice_ids()[0], 1u);
1362 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[0], 2007000);
1363 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[0], 0);
1364 EXPECT_EQ(storage_->thread_slices().thread_instruction_counts()[0], 0);
1365 EXPECT_EQ(storage_->thread_slices().thread_instruction_deltas()[0], 0);
1366 EXPECT_EQ(storage_->thread_slices().slice_ids()[1], 2u);
1367 EXPECT_EQ(storage_->thread_slices().thread_timestamp_ns()[1], 2008000);
1368 EXPECT_EQ(storage_->thread_slices().thread_duration_ns()[1], 0);
1369 EXPECT_EQ(storage_->thread_slices().thread_instruction_counts()[1], 0);
1370 EXPECT_EQ(storage_->thread_slices().thread_instruction_deltas()[1], 0);
1371}
1372
Eric Seckler56a007d2019-05-02 16:25:14 +01001373TEST_F(ProtoTraceParserTest, TrackEventWithoutIncrementalStateReset) {
Eric Seckler56a007d2019-05-02 16:25:14 +01001374 context_.sorter.reset(new TraceSorter(
1375 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
1376
1377 {
1378 auto* packet = trace_.add_packet();
1379 packet->set_trusted_packet_sequence_id(1);
1380 auto* thread_desc = packet->set_thread_descriptor();
1381 thread_desc->set_pid(15);
1382 thread_desc->set_tid(16);
1383 thread_desc->set_reference_timestamp_us(1000);
1384 thread_desc->set_reference_thread_time_us(2000);
1385 }
1386 {
1387 // Event should be discarded because incremental state was never cleared.
1388 auto* packet = trace_.add_packet();
1389 packet->set_trusted_packet_sequence_id(1);
1390 auto* event = packet->set_track_event();
1391 event->set_timestamp_delta_us(10); // absolute: 1010.
1392 event->set_thread_time_delta_us(5); // absolute: 2005.
1393 event->add_category_iids(1);
1394 auto* legacy_event = event->set_legacy_event();
1395 legacy_event->set_name_iid(1);
1396 legacy_event->set_phase('B');
1397 }
1398
1399 Tokenize();
1400
Lalit Magantic7ea02e2019-12-12 14:06:49 +00001401 EXPECT_CALL(*slice_, Begin(_, _, _, _, _)).Times(0);
Eric Seckler56a007d2019-05-02 16:25:14 +01001402 context_.sorter->ExtractEventsForced();
1403}
1404
1405TEST_F(ProtoTraceParserTest, TrackEventWithoutThreadDescriptor) {
Eric Seckler56a007d2019-05-02 16:25:14 +01001406 context_.sorter.reset(new TraceSorter(
1407 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
1408
1409 {
1410 // Event should be discarded because no thread descriptor was seen yet.
1411 auto* packet = trace_.add_packet();
1412 packet->set_trusted_packet_sequence_id(1);
1413 packet->set_incremental_state_cleared(true);
1414 auto* event = packet->set_track_event();
1415 event->set_timestamp_delta_us(10);
1416 event->set_thread_time_delta_us(5);
1417 event->add_category_iids(1);
1418 auto* legacy_event = event->set_legacy_event();
1419 legacy_event->set_name_iid(1);
1420 legacy_event->set_phase('B');
1421 }
1422
1423 Tokenize();
1424
Lalit Magantic7ea02e2019-12-12 14:06:49 +00001425 EXPECT_CALL(*slice_, Begin(_, _, _, _, _)).Times(0);
Eric Seckler56a007d2019-05-02 16:25:14 +01001426 context_.sorter->ExtractEventsForced();
1427}
1428
1429TEST_F(ProtoTraceParserTest, TrackEventWithDataLoss) {
Eric Seckler56a007d2019-05-02 16:25:14 +01001430 context_.sorter.reset(new TraceSorter(
1431 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
1432
1433 {
1434 auto* packet = trace_.add_packet();
1435 packet->set_trusted_packet_sequence_id(1);
1436 packet->set_incremental_state_cleared(true);
1437 auto* thread_desc = packet->set_thread_descriptor();
1438 thread_desc->set_pid(15);
1439 thread_desc->set_tid(16);
1440 thread_desc->set_reference_timestamp_us(1000);
1441 thread_desc->set_reference_thread_time_us(2000);
1442 }
1443 {
1444 auto* packet = trace_.add_packet();
1445 packet->set_trusted_packet_sequence_id(1);
1446 auto* event = packet->set_track_event();
1447 event->set_timestamp_delta_us(10); // absolute: 1010.
1448 event->set_thread_time_delta_us(5); // absolute: 2005.
1449 event->add_category_iids(1);
1450 auto* legacy_event = event->set_legacy_event();
1451 legacy_event->set_name_iid(1);
1452 legacy_event->set_phase('B');
1453 }
1454 {
1455 // Event should be dropped because data loss occurred before.
1456 auto* packet = trace_.add_packet();
1457 packet->set_trusted_packet_sequence_id(1);
1458 packet->set_previous_packet_dropped(true); // Data loss occurred.
1459 auto* event = packet->set_track_event();
1460 event->set_timestamp_delta_us(10);
1461 event->set_thread_time_delta_us(5);
1462 event->add_category_iids(1);
1463 auto* legacy_event = event->set_legacy_event();
1464 legacy_event->set_name_iid(1);
1465 legacy_event->set_phase('E');
1466 }
1467 {
1468 // Event should be dropped because incremental state is invalid.
1469 auto* packet = trace_.add_packet();
1470 packet->set_trusted_packet_sequence_id(1);
1471 auto* event = packet->set_track_event();
1472 event->set_timestamp_delta_us(10);
1473 event->set_thread_time_delta_us(5);
1474 event->add_category_iids(1);
1475 auto* legacy_event = event->set_legacy_event();
1476 legacy_event->set_name_iid(1);
1477 legacy_event->set_phase('E');
1478 }
1479 {
1480 // Event should be dropped because no new thread descriptor was seen yet.
1481 auto* packet = trace_.add_packet();
1482 packet->set_trusted_packet_sequence_id(1);
1483 packet->set_incremental_state_cleared(true);
1484 auto* event = packet->set_track_event();
1485 event->set_timestamp_delta_us(10);
1486 event->set_thread_time_delta_us(5);
1487 event->add_category_iids(1);
1488 auto* legacy_event = event->set_legacy_event();
1489 legacy_event->set_name_iid(1);
1490 legacy_event->set_phase('E');
1491 }
1492 {
1493 auto* packet = trace_.add_packet();
1494 packet->set_trusted_packet_sequence_id(1);
1495 auto* thread_desc = packet->set_thread_descriptor();
1496 thread_desc->set_pid(15);
1497 thread_desc->set_tid(16);
1498 thread_desc->set_reference_timestamp_us(2000);
1499 thread_desc->set_reference_thread_time_us(3000);
1500 }
1501 {
1502 auto* packet = trace_.add_packet();
1503 packet->set_trusted_packet_sequence_id(1);
1504 auto* event = packet->set_track_event();
1505 event->set_timestamp_delta_us(10); // absolute: 2010.
1506 event->set_thread_time_delta_us(5); // absolute: 3005.
1507 event->add_category_iids(1);
1508 auto* legacy_event = event->set_legacy_event();
1509 legacy_event->set_name_iid(1);
1510 legacy_event->set_phase('E');
1511 }
1512
1513 Tokenize();
1514
1515 EXPECT_CALL(*process_, UpdateThread(16, 15))
Eric Seckler56a007d2019-05-02 16:25:14 +01001516 .WillRepeatedly(Return(1));
1517
Lalit Magantieac7fff2020-01-10 16:42:54 +00001518 tables::ThreadTable::Row row(16);
1519 row.upid = 1u;
1520 storage_->mutable_thread_table()->Insert(row);
Eric Secklerb32cacf2019-09-27 16:51:19 +01001521
Lalit Magantib0e11f62020-01-02 14:17:58 +00001522 constexpr TrackId track{0u};
Eric Seckler56a007d2019-05-02 16:25:14 +01001523 InSequence in_sequence; // Below slices should be sorted by timestamp.
Lalit Magantic7ea02e2019-12-12 14:06:49 +00001524 EXPECT_CALL(*slice_, Begin(1010000, track, kNullStringId, kNullStringId, _));
Lalit Maganti21b21632019-09-28 16:50:23 +01001525 EXPECT_CALL(*slice_, End(2010000, track, kNullStringId, kNullStringId, _));
Eric Seckler56a007d2019-05-02 16:25:14 +01001526
1527 context_.sorter->ExtractEventsForced();
1528}
1529
1530TEST_F(ProtoTraceParserTest, TrackEventMultipleSequences) {
Eric Seckler56a007d2019-05-02 16:25:14 +01001531 context_.sorter.reset(new TraceSorter(
1532 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
1533
1534 {
1535 auto* packet = trace_.add_packet();
1536 packet->set_trusted_packet_sequence_id(1);
1537 packet->set_incremental_state_cleared(true);
1538 auto* thread_desc = packet->set_thread_descriptor();
1539 thread_desc->set_pid(15);
1540 thread_desc->set_tid(16);
1541 thread_desc->set_reference_timestamp_us(1000);
1542 thread_desc->set_reference_thread_time_us(2000);
1543 }
1544 {
1545 auto* packet = trace_.add_packet();
1546 packet->set_trusted_packet_sequence_id(1);
1547 auto* event = packet->set_track_event();
1548 event->set_timestamp_delta_us(10); // absolute: 1010.
1549 event->set_thread_time_delta_us(5); // absolute: 2005.
1550 event->add_category_iids(1);
1551 auto* legacy_event = event->set_legacy_event();
1552 legacy_event->set_name_iid(1);
1553 legacy_event->set_phase('B');
1554
1555 auto* interned_data = packet->set_interned_data();
1556 auto cat1 = interned_data->add_event_categories();
1557 cat1->set_iid(1);
1558 cat1->set_name("cat1");
Eric Seckler0c460ef2019-08-14 15:42:36 +01001559 auto ev1 = interned_data->add_event_names();
Eric Seckler56a007d2019-05-02 16:25:14 +01001560 ev1->set_iid(1);
1561 ev1->set_name("ev1");
1562 }
1563 {
1564 auto* packet = trace_.add_packet();
1565 packet->set_trusted_packet_sequence_id(2);
1566 packet->set_incremental_state_cleared(true);
1567 auto* thread_desc = packet->set_thread_descriptor();
1568 thread_desc->set_pid(15);
1569 thread_desc->set_tid(17);
1570 thread_desc->set_reference_timestamp_us(995);
1571 thread_desc->set_reference_thread_time_us(3000);
1572 }
1573 {
1574 auto* packet = trace_.add_packet();
1575 packet->set_trusted_packet_sequence_id(2);
1576 auto* event = packet->set_track_event();
1577 event->set_timestamp_delta_us(10); // absolute: 1005.
1578 event->set_thread_time_delta_us(5); // absolute: 3005.
1579 event->add_category_iids(1);
1580 auto* legacy_event = event->set_legacy_event();
1581 legacy_event->set_name_iid(1);
1582 legacy_event->set_phase('B');
1583
1584 auto* interned_data = packet->set_interned_data();
1585 auto cat1 = interned_data->add_event_categories();
1586 cat1->set_iid(1);
1587 cat1->set_name("cat1");
Eric Seckler0c460ef2019-08-14 15:42:36 +01001588 auto ev2 = interned_data->add_event_names();
Eric Seckler56a007d2019-05-02 16:25:14 +01001589 ev2->set_iid(1);
1590 ev2->set_name("ev2");
1591 }
1592 {
1593 auto* packet = trace_.add_packet();
1594 packet->set_trusted_packet_sequence_id(1);
1595 auto* event = packet->set_track_event();
1596 event->set_timestamp_delta_us(10); // absolute: 1020.
1597 event->set_thread_time_delta_us(5); // absolute: 2010.
1598 event->add_category_iids(1);
1599 auto* legacy_event = event->set_legacy_event();
1600 legacy_event->set_name_iid(1);
1601 legacy_event->set_phase('E');
1602 }
1603 {
1604 auto* packet = trace_.add_packet();
1605 packet->set_trusted_packet_sequence_id(2);
1606 auto* event = packet->set_track_event();
1607 event->set_timestamp_delta_us(10); // absolute: 1015.
1608 event->set_thread_time_delta_us(5); // absolute: 3015.
1609 event->add_category_iids(1);
1610 auto* legacy_event = event->set_legacy_event();
1611 legacy_event->set_name_iid(1);
1612 legacy_event->set_phase('E');
1613 }
1614
1615 Tokenize();
1616
1617 EXPECT_CALL(*process_, UpdateThread(16, 15))
Eric Seckler56a007d2019-05-02 16:25:14 +01001618 .WillRepeatedly(Return(1));
1619 EXPECT_CALL(*process_, UpdateThread(17, 15))
Eric Seckler56a007d2019-05-02 16:25:14 +01001620 .WillRepeatedly(Return(2));
1621
Lalit Magantieac7fff2020-01-10 16:42:54 +00001622 tables::ThreadTable::Row t1(16);
1623 t1.upid = 1u;
1624 storage_->mutable_thread_table()->Insert(t1);
Eric Secklerb32cacf2019-09-27 16:51:19 +01001625
Lalit Magantieac7fff2020-01-10 16:42:54 +00001626 tables::ThreadTable::Row t2(17);
1627 t2.upid = 1u;
1628 storage_->mutable_thread_table()->Insert(t2);
Eric Secklerb32cacf2019-09-27 16:51:19 +01001629
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001630 StringId cat_1 = storage_->InternString("cat1");
1631 StringId ev_2 = storage_->InternString("ev2");
1632 StringId ev_1 = storage_->InternString("ev1");
Eric Seckler02cdcef2019-10-14 08:56:28 +01001633
Lalit Magantib0e11f62020-01-02 14:17:58 +00001634 constexpr TrackId thread_2_track{0u};
1635 constexpr TrackId thread_1_track{1u};
Eric Seckler56a007d2019-05-02 16:25:14 +01001636 InSequence in_sequence; // Below slices should be sorted by timestamp.
1637
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001638 EXPECT_CALL(*slice_, Begin(1005000, thread_2_track, cat_1, ev_2, _));
1639 EXPECT_CALL(*slice_, Begin(1010000, thread_1_track, cat_1, ev_1, _));
1640 EXPECT_CALL(*slice_, End(1015000, thread_2_track, cat_1, ev_2, _));
1641 EXPECT_CALL(*slice_, End(1020000, thread_1_track, cat_1, ev_1, _));
Eric Seckler56a007d2019-05-02 16:25:14 +01001642
1643 context_.sorter->ExtractEventsForced();
1644}
1645
Eric Secklerc93823e2019-06-03 16:49:19 +01001646TEST_F(ProtoTraceParserTest, TrackEventWithDebugAnnotations) {
Eric Secklerc93823e2019-06-03 16:49:19 +01001647 context_.sorter.reset(new TraceSorter(
1648 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
Lalit Maganti7449dc82019-12-30 15:52:35 +00001649 MockBoundInserter inserter;
Eric Secklerc93823e2019-06-03 16:49:19 +01001650
1651 {
1652 auto* packet = trace_.add_packet();
1653 packet->set_trusted_packet_sequence_id(1);
1654 packet->set_incremental_state_cleared(true);
1655 auto* thread_desc = packet->set_thread_descriptor();
1656 thread_desc->set_pid(15);
1657 thread_desc->set_tid(16);
1658 thread_desc->set_reference_timestamp_us(1000);
1659 thread_desc->set_reference_thread_time_us(2000);
1660 }
1661 {
1662 auto* packet = trace_.add_packet();
1663 packet->set_trusted_packet_sequence_id(1);
1664 auto* event = packet->set_track_event();
1665 event->set_timestamp_delta_us(10); // absolute: 1010.
1666 event->set_thread_time_delta_us(5); // absolute: 2005.
1667 event->add_category_iids(1);
1668 auto* annotation1 = event->add_debug_annotations();
1669 annotation1->set_name_iid(1);
1670 annotation1->set_uint_value(10u);
1671 auto* annotation2 = event->add_debug_annotations();
1672 annotation2->set_name_iid(2);
1673 auto* nested = annotation2->set_nested_value();
1674 nested->set_nested_type(protos::pbzero::DebugAnnotation::NestedValue::DICT);
1675 nested->add_dict_keys("child1");
1676 nested->add_dict_keys("child2");
1677 auto* child1 = nested->add_dict_values();
1678 child1->set_nested_type(
1679 protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
1680 child1->set_bool_value(true);
1681 auto* child2 = nested->add_dict_values();
1682 child2->set_nested_type(
1683 protos::pbzero::DebugAnnotation::NestedValue::ARRAY);
1684 auto* child21 = child2->add_array_values();
1685 child21->set_nested_type(
1686 protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
1687 child21->set_string_value("child21");
1688 auto* child22 = child2->add_array_values();
1689 child22->set_nested_type(
1690 protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
1691 child22->set_double_value(2.2);
1692 auto* child23 = child2->add_array_values();
1693 child23->set_nested_type(
1694 protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
1695 child23->set_int_value(23);
1696 auto* legacy_event = event->set_legacy_event();
1697 legacy_event->set_name_iid(1);
1698 legacy_event->set_phase('B');
1699
1700 auto* interned_data = packet->set_interned_data();
1701 auto cat1 = interned_data->add_event_categories();
1702 cat1->set_iid(1);
1703 cat1->set_name("cat1");
Eric Seckler0c460ef2019-08-14 15:42:36 +01001704 auto ev1 = interned_data->add_event_names();
Eric Secklerc93823e2019-06-03 16:49:19 +01001705 ev1->set_iid(1);
1706 ev1->set_name("ev1");
1707 auto an1 = interned_data->add_debug_annotation_names();
1708 an1->set_iid(1);
1709 an1->set_name("an1");
1710 auto an2 = interned_data->add_debug_annotation_names();
1711 an2->set_iid(2);
1712 an2->set_name("an2");
1713 }
1714 {
1715 auto* packet = trace_.add_packet();
1716 packet->set_trusted_packet_sequence_id(1);
1717 auto* event = packet->set_track_event();
1718 event->set_timestamp_delta_us(10); // absolute: 1020.
1719 event->set_thread_time_delta_us(5); // absolute: 2010.
1720 event->add_category_iids(1);
1721 auto* annotation3 = event->add_debug_annotations();
1722 annotation3->set_name_iid(3);
1723 annotation3->set_int_value(-3);
1724 auto* annotation4 = event->add_debug_annotations();
1725 annotation4->set_name_iid(4);
1726 annotation4->set_bool_value(true);
1727 auto* annotation5 = event->add_debug_annotations();
1728 annotation5->set_name_iid(5);
1729 annotation5->set_double_value(-5.5);
1730 auto* annotation6 = event->add_debug_annotations();
1731 annotation6->set_name_iid(6);
1732 annotation6->set_pointer_value(20u);
1733 auto* annotation7 = event->add_debug_annotations();
1734 annotation7->set_name_iid(7);
1735 annotation7->set_string_value("val7");
1736 auto* annotation8 = event->add_debug_annotations();
1737 annotation8->set_name_iid(8);
1738 annotation8->set_legacy_json_value("val8");
Mikhail Khokhlovac134ed2020-01-07 14:35:49 +00001739 auto* annotation9 = event->add_debug_annotations();
1740 annotation9->set_name_iid(9);
1741 annotation9->set_int_value(15);
Eric Secklerc93823e2019-06-03 16:49:19 +01001742 auto* legacy_event = event->set_legacy_event();
1743 legacy_event->set_name_iid(1);
1744 legacy_event->set_phase('E');
1745
1746 auto* interned_data = packet->set_interned_data();
1747 auto an3 = interned_data->add_debug_annotation_names();
1748 an3->set_iid(3);
1749 an3->set_name("an3");
1750 auto an4 = interned_data->add_debug_annotation_names();
1751 an4->set_iid(4);
1752 an4->set_name("an4");
1753 auto an5 = interned_data->add_debug_annotation_names();
1754 an5->set_iid(5);
1755 an5->set_name("an5");
1756 auto an6 = interned_data->add_debug_annotation_names();
1757 an6->set_iid(6);
1758 an6->set_name("an6");
1759 auto an7 = interned_data->add_debug_annotation_names();
1760 an7->set_iid(7);
1761 an7->set_name("an7");
1762 auto an8 = interned_data->add_debug_annotation_names();
1763 an8->set_iid(8);
1764 an8->set_name("an8");
Mikhail Khokhlovac134ed2020-01-07 14:35:49 +00001765 auto an9 = interned_data->add_debug_annotation_names();
1766 an9->set_iid(9);
1767 an9->set_name("an8.foo");
Eric Secklerc93823e2019-06-03 16:49:19 +01001768 }
1769
1770 Tokenize();
1771
1772 EXPECT_CALL(*process_, UpdateThread(16, 15))
Eric Secklerc93823e2019-06-03 16:49:19 +01001773 .WillRepeatedly(Return(1));
1774
Lalit Magantieac7fff2020-01-10 16:42:54 +00001775 tables::ThreadTable::Row row(16);
1776 row.upid = 1u;
1777 storage_->mutable_thread_table()->Insert(row);
Eric Secklerb32cacf2019-09-27 16:51:19 +01001778
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001779 StringId cat_1 = storage_->InternString("cat1");
1780 StringId ev_1 = storage_->InternString("ev1");
1781 StringId debug_an_1 = storage_->InternString("debug.an1");
1782 StringId debug_an_2_child_1 = storage_->InternString("debug.an2.child1");
1783 StringId debug_an_2_child_2 = storage_->InternString("debug.an2.child2");
1784 StringId debug_an_2_child_2_0 = storage_->InternString("debug.an2.child2[0]");
1785 StringId child21 = storage_->InternString("child21");
1786 StringId debug_an_2_child_2_1 = storage_->InternString("debug.an2.child2[1]");
1787 StringId debug_an_2_child_2_2 = storage_->InternString("debug.an2.child2[2]");
1788 StringId debug_an_3 = storage_->InternString("debug.an3");
1789 StringId debug_an_4 = storage_->InternString("debug.an4");
1790 StringId debug_an_5 = storage_->InternString("debug.an5");
1791 StringId debug_an_6 = storage_->InternString("debug.an6");
1792 StringId debug_an_7 = storage_->InternString("debug.an7");
1793 StringId val_7 = storage_->InternString("val7");
1794 StringId debug_an_8 = storage_->InternString("debug.an8");
1795 StringId val_8 = storage_->InternString("val8");
1796 StringId debug_an_8_foo = storage_->InternString("debug.an8_foo");
Eric Seckler02cdcef2019-10-14 08:56:28 +01001797
Lalit Magantib0e11f62020-01-02 14:17:58 +00001798 constexpr TrackId track{0u};
Eric Seckler02cdcef2019-10-14 08:56:28 +01001799 InSequence in_sequence; // Below slices should be sorted by timestamp.
1800
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001801 EXPECT_CALL(*slice_, Begin(1010000, track, cat_1, ev_1, _))
Lalit Maganti7449dc82019-12-30 15:52:35 +00001802 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(1u)));
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001803 EXPECT_CALL(inserter,
1804 AddArg(debug_an_1, debug_an_1, Variadic::UnsignedInteger(10u)));
Lalit Magantif0599a02020-01-15 15:45:20 +00001805
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001806 EXPECT_CALL(inserter, AddArg(debug_an_2_child_1, debug_an_2_child_1,
Lalit Magantif0599a02020-01-15 15:45:20 +00001807 Variadic::Boolean(true)));
1808
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001809 EXPECT_CALL(inserter, AddArg(debug_an_2_child_2, debug_an_2_child_2_0,
1810 Variadic::String(child21)));
Eric Seckler02cdcef2019-10-14 08:56:28 +01001811
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001812 EXPECT_CALL(inserter, AddArg(debug_an_2_child_2, debug_an_2_child_2_1,
1813 Variadic::Real(2.2)));
Eric Seckler02cdcef2019-10-14 08:56:28 +01001814
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001815 EXPECT_CALL(inserter, AddArg(debug_an_2_child_2, debug_an_2_child_2_2,
Lalit Magantif0599a02020-01-15 15:45:20 +00001816 Variadic::Integer(23)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001817
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001818 EXPECT_CALL(*slice_, End(1020000, track, cat_1, ev_1, _))
Lalit Maganti7449dc82019-12-30 15:52:35 +00001819 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(1u)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001820
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001821 EXPECT_CALL(inserter, AddArg(debug_an_3, debug_an_3, Variadic::Integer(-3)));
1822 EXPECT_CALL(inserter,
1823 AddArg(debug_an_4, debug_an_4, Variadic::Boolean(true)));
1824 EXPECT_CALL(inserter, AddArg(debug_an_5, debug_an_5, Variadic::Real(-5.5)));
1825 EXPECT_CALL(inserter, AddArg(debug_an_6, debug_an_6, Variadic::Pointer(20u)));
1826 EXPECT_CALL(inserter,
1827 AddArg(debug_an_7, debug_an_7, Variadic::String(val_7)));
1828 EXPECT_CALL(inserter, AddArg(debug_an_8, debug_an_8, Variadic::Json(val_8)));
1829 EXPECT_CALL(inserter,
1830 AddArg(debug_an_8_foo, debug_an_8_foo, Variadic::Integer(15)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001831
1832 context_.sorter->ExtractEventsForced();
1833}
1834
1835TEST_F(ProtoTraceParserTest, TrackEventWithTaskExecution) {
Eric Secklerc93823e2019-06-03 16:49:19 +01001836 context_.sorter.reset(new TraceSorter(
1837 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
Eric Secklerc93823e2019-06-03 16:49:19 +01001838
1839 {
1840 auto* packet = trace_.add_packet();
1841 packet->set_trusted_packet_sequence_id(1);
1842 packet->set_incremental_state_cleared(true);
1843 auto* thread_desc = packet->set_thread_descriptor();
1844 thread_desc->set_pid(15);
1845 thread_desc->set_tid(16);
1846 thread_desc->set_reference_timestamp_us(1000);
1847 thread_desc->set_reference_thread_time_us(2000);
1848 }
1849 {
1850 auto* packet = trace_.add_packet();
1851 packet->set_trusted_packet_sequence_id(1);
1852 auto* event = packet->set_track_event();
1853 event->set_timestamp_delta_us(10); // absolute: 1010.
1854 event->set_thread_time_delta_us(5); // absolute: 2005.
1855 event->add_category_iids(1);
1856 auto* task_execution = event->set_task_execution();
1857 task_execution->set_posted_from_iid(1);
1858 auto* legacy_event = event->set_legacy_event();
1859 legacy_event->set_name_iid(1);
1860 legacy_event->set_phase('B');
1861
1862 auto* interned_data = packet->set_interned_data();
1863 auto cat1 = interned_data->add_event_categories();
1864 cat1->set_iid(1);
1865 cat1->set_name("cat1");
Eric Seckler0c460ef2019-08-14 15:42:36 +01001866 auto ev1 = interned_data->add_event_names();
Eric Secklerc93823e2019-06-03 16:49:19 +01001867 ev1->set_iid(1);
1868 ev1->set_name("ev1");
1869 auto loc1 = interned_data->add_source_locations();
1870 loc1->set_iid(1);
1871 loc1->set_file_name("file1");
1872 loc1->set_function_name("func1");
Nicolò Mazzucato6261d732019-08-30 13:15:17 +01001873 loc1->set_line_number(42);
Eric Secklerc93823e2019-06-03 16:49:19 +01001874 }
1875
1876 Tokenize();
1877
Eric Seckler3183c6d2020-01-14 15:45:20 +00001878 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillRepeatedly(Return(1));
Eric Secklerc93823e2019-06-03 16:49:19 +01001879
Lalit Magantieac7fff2020-01-10 16:42:54 +00001880 tables::ThreadTable::Row row(16);
1881 row.upid = 1u;
1882 storage_->mutable_thread_table()->Insert(row);
Eric Secklerb32cacf2019-09-27 16:51:19 +01001883
Lalit Magantib0e11f62020-01-02 14:17:58 +00001884 constexpr TrackId track{0u};
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001885
1886 StringId cat_1 = storage_->InternString("cat1");
1887 StringId ev_1 = storage_->InternString("ev1");
1888 StringId file_1 = storage_->InternString("file1");
1889 StringId func_1 = storage_->InternString("func1");
1890
Eric Secklerc93823e2019-06-03 16:49:19 +01001891 InSequence in_sequence; // Below slices should be sorted by timestamp.
1892
Lalit Maganti7449dc82019-12-30 15:52:35 +00001893 MockBoundInserter inserter;
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001894 EXPECT_CALL(*slice_, Begin(1010000, track, cat_1, ev_1, _))
Lalit Maganti7449dc82019-12-30 15:52:35 +00001895 .WillOnce(DoAll(InvokeArgument<4>(&inserter), Return(1u)));
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001896 EXPECT_CALL(inserter, AddArg(_, _, Variadic::String(file_1)));
1897 EXPECT_CALL(inserter, AddArg(_, _, Variadic::String(func_1)));
Lalit Maganti7449dc82019-12-30 15:52:35 +00001898 EXPECT_CALL(inserter, AddArg(_, _, Variadic::UnsignedInteger(42)));
Eric Secklerc93823e2019-06-03 16:49:19 +01001899
1900 context_.sorter->ExtractEventsForced();
1901}
1902
Nicolò Mazzucato8f75ede2019-08-12 17:36:36 +01001903TEST_F(ProtoTraceParserTest, TrackEventWithLogMessage) {
1904 context_.sorter.reset(new TraceSorter(
1905 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
Nicolò Mazzucato8f75ede2019-08-12 17:36:36 +01001906
1907 {
1908 auto* packet = trace_.add_packet();
1909 packet->set_trusted_packet_sequence_id(1);
1910 packet->set_incremental_state_cleared(true);
1911 auto* thread_desc = packet->set_thread_descriptor();
1912 thread_desc->set_pid(15);
1913 thread_desc->set_tid(16);
1914 thread_desc->set_reference_timestamp_us(1000);
1915 thread_desc->set_reference_thread_time_us(2000);
1916 }
1917 {
1918 auto* packet = trace_.add_packet();
1919 packet->set_trusted_packet_sequence_id(1);
1920 auto* event = packet->set_track_event();
1921 event->set_timestamp_delta_us(10); // absolute: 1010.
1922 event->set_thread_time_delta_us(5); // absolute: 2005.
1923 event->add_category_iids(1);
1924
1925 auto* log_message = event->set_log_message();
1926 log_message->set_body_iid(1);
1927 log_message->set_source_location_iid(1);
1928
1929 auto* legacy_event = event->set_legacy_event();
1930 legacy_event->set_name_iid(1);
1931 legacy_event->set_phase('I');
1932
1933 auto* interned_data = packet->set_interned_data();
1934 auto cat1 = interned_data->add_event_categories();
1935 cat1->set_iid(1);
1936 cat1->set_name("cat1");
1937
Eric Seckler0c460ef2019-08-14 15:42:36 +01001938 auto ev1 = interned_data->add_event_names();
Nicolò Mazzucato8f75ede2019-08-12 17:36:36 +01001939 ev1->set_iid(1);
1940 ev1->set_name("ev1");
1941
1942 auto body = interned_data->add_log_message_body();
1943 body->set_iid(1);
1944 body->set_body("body1");
1945
1946 auto loc1 = interned_data->add_source_locations();
1947 loc1->set_iid(1);
1948 loc1->set_file_name("file1");
1949 loc1->set_function_name("func1");
1950 loc1->set_line_number(1);
1951 }
1952
1953 Tokenize();
1954
Eric Seckler3183c6d2020-01-14 15:45:20 +00001955 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillRepeatedly(Return(1));
Nicolò Mazzucato8f75ede2019-08-12 17:36:36 +01001956
Lalit Magantieac7fff2020-01-10 16:42:54 +00001957 tables::ThreadTable::Row row(16);
1958 row.upid = 1u;
1959 storage_->mutable_thread_table()->Insert(row);
Eric Secklerb32cacf2019-09-27 16:51:19 +01001960
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001961 StringId cat_1 = storage_->InternString("cat1");
1962 StringId ev_1 = storage_->InternString("ev1");
1963 StringId body_1 = storage_->InternString("body1");
1964
Lalit Magantib0e11f62020-01-02 14:17:58 +00001965 constexpr TrackId track{0};
Nicolò Mazzucato8f75ede2019-08-12 17:36:36 +01001966 InSequence in_sequence; // Below slices should be sorted by timestamp.
1967
Lalit Maganti7449dc82019-12-30 15:52:35 +00001968 MockBoundInserter inserter;
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001969 EXPECT_CALL(*slice_, Scoped(1010000, track, cat_1, ev_1, 0, _))
Lalit Maganti7449dc82019-12-30 15:52:35 +00001970 .WillOnce(DoAll(InvokeArgument<5>(&inserter), Return(1u)));
Nicolò Mazzucato8f75ede2019-08-12 17:36:36 +01001971
Nicolò Mazzucato8f75ede2019-08-12 17:36:36 +01001972 // Call with logMessageBody (body1 in this case).
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001973 EXPECT_CALL(inserter, AddArg(_, _, Variadic::String(body_1)));
Nicolò Mazzucato8f75ede2019-08-12 17:36:36 +01001974
1975 context_.sorter->ExtractEventsForced();
1976
Lalit Magantif1ab24f2020-01-07 17:42:26 +00001977 EXPECT_GT(context_.storage->android_log_table().row_count(), 0u);
1978 EXPECT_EQ(context_.storage->android_log_table().ts()[0], 1010000);
Lalit Maganti47bc3d62020-01-15 16:21:22 +00001979 EXPECT_EQ(context_.storage->android_log_table().msg()[0], body_1);
Nicolò Mazzucato8f75ede2019-08-12 17:36:36 +01001980}
1981
Eric Secklerb7e26332019-07-19 12:46:17 +01001982TEST_F(ProtoTraceParserTest, TrackEventParseLegacyEventIntoRawTable) {
1983 context_.sorter.reset(new TraceSorter(
1984 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
1985
1986 {
1987 auto* packet = trace_.add_packet();
1988 packet->set_trusted_packet_sequence_id(1);
1989 packet->set_incremental_state_cleared(true);
1990 auto* thread_desc = packet->set_thread_descriptor();
1991 thread_desc->set_pid(15);
1992 thread_desc->set_tid(16);
1993 thread_desc->set_reference_timestamp_us(1000);
1994 thread_desc->set_reference_thread_time_us(2000);
1995 }
1996 {
1997 auto* packet = trace_.add_packet();
1998 packet->set_trusted_packet_sequence_id(1);
1999 auto* event = packet->set_track_event();
2000 event->set_timestamp_delta_us(10); // absolute: 1010.
2001 event->set_thread_time_delta_us(5); // absolute: 2005.
2002 event->add_category_iids(1);
2003
2004 auto* legacy_event = event->set_legacy_event();
2005 legacy_event->set_name_iid(1);
2006 // Represents a phase that isn't parsed into regular trace processor tables.
2007 legacy_event->set_phase('?');
2008 legacy_event->set_duration_us(23);
2009 legacy_event->set_thread_duration_us(15);
2010 legacy_event->set_global_id(99u);
2011 legacy_event->set_id_scope("scope1");
2012 legacy_event->set_use_async_tts('?');
2013 legacy_event->set_bind_id(98);
2014 legacy_event->set_bind_to_enclosing(true);
2015 legacy_event->set_flow_direction(
2016 protos::pbzero::TrackEvent::LegacyEvent::FLOW_INOUT);
2017
2018 auto* annotation1 = event->add_debug_annotations();
2019 annotation1->set_name_iid(1);
2020 annotation1->set_uint_value(10u);
2021
2022 auto* interned_data = packet->set_interned_data();
2023 auto cat1 = interned_data->add_event_categories();
2024 cat1->set_iid(1);
2025 cat1->set_name("cat1");
Eric Seckler0c460ef2019-08-14 15:42:36 +01002026 auto ev1 = interned_data->add_event_names();
Eric Secklerb7e26332019-07-19 12:46:17 +01002027 ev1->set_iid(1);
2028 ev1->set_name("ev1");
2029 auto an1 = interned_data->add_debug_annotation_names();
2030 an1->set_iid(1);
2031 an1->set_name("an1");
2032 }
2033
2034 Tokenize();
2035
Eric Seckler3183c6d2020-01-14 15:45:20 +00002036 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillRepeatedly(Return(1));
Eric Secklerb7e26332019-07-19 12:46:17 +01002037
Lalit Magantieac7fff2020-01-10 16:42:54 +00002038 tables::ThreadTable::Row row(16);
2039 row.upid = 1u;
2040 storage_->mutable_thread_table()->Insert(row);
Eric Secklerb32cacf2019-09-27 16:51:19 +01002041
Lalit Maganti47bc3d62020-01-15 16:21:22 +00002042 StringId cat_1 = storage_->InternString("cat1");
2043 StringId ev_1 = storage_->InternString("ev1");
2044 StringId scope_1 = storage_->InternString("scope1");
2045 StringId question = storage_->InternString("?");
2046 StringId debug_an_1 = storage_->InternString("debug.an1");
Eric Secklerb7e26332019-07-19 12:46:17 +01002047
2048 context_.sorter->ExtractEventsForced();
2049
2050 ::testing::Mock::VerifyAndClearExpectations(storage_);
2051
Lalit Maganti679b29d2020-01-13 13:26:28 +00002052 // Verify raw_table and args contents.
2053 const auto& raw_table = storage_->raw_table();
2054 EXPECT_EQ(raw_table.row_count(), 1u);
2055 EXPECT_EQ(raw_table.ts()[0], 1010000);
2056 EXPECT_EQ(raw_table.name()[0],
Eric Secklerb7e26332019-07-19 12:46:17 +01002057 storage_->InternString("track_event.legacy_event"));
Lalit Maganti679b29d2020-01-13 13:26:28 +00002058 EXPECT_EQ(raw_table.cpu()[0], 0u);
2059 EXPECT_EQ(raw_table.utid()[0], 1u);
2060 EXPECT_EQ(raw_table.arg_set_id()[0], 1u);
Eric Secklerb7e26332019-07-19 12:46:17 +01002061
Lalit Maganti1908e262020-01-09 14:33:19 +00002062 EXPECT_GE(storage_->arg_table().row_count(), 13u);
Eric Secklerb7e26332019-07-19 12:46:17 +01002063
2064 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.category"),
Lalit Maganti47bc3d62020-01-15 16:21:22 +00002065 Variadic::String(cat_1)));
Eric Secklerb7e26332019-07-19 12:46:17 +01002066 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.name"),
Lalit Maganti47bc3d62020-01-15 16:21:22 +00002067 Variadic::String(ev_1)));
Eric Secklerb7e26332019-07-19 12:46:17 +01002068 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.phase"),
Lalit Maganti47bc3d62020-01-15 16:21:22 +00002069 Variadic::String(question)));
Eric Secklerb7e26332019-07-19 12:46:17 +01002070 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.duration_ns"),
2071 Variadic::Integer(23000)));
2072 EXPECT_TRUE(HasArg(1u,
2073 storage_->InternString("legacy_event.thread_timestamp_ns"),
2074 Variadic::Integer(2005000)));
2075 EXPECT_TRUE(HasArg(1u,
2076 storage_->InternString("legacy_event.thread_duration_ns"),
2077 Variadic::Integer(15000)));
2078 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.use_async_tts"),
2079 Variadic::Boolean(true)));
2080 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.global_id"),
2081 Variadic::UnsignedInteger(99u)));
2082 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.id_scope"),
Lalit Maganti47bc3d62020-01-15 16:21:22 +00002083 Variadic::String(scope_1)));
Eric Secklerb7e26332019-07-19 12:46:17 +01002084 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.bind_id"),
2085 Variadic::UnsignedInteger(98u)));
2086 EXPECT_TRUE(HasArg(1u,
2087 storage_->InternString("legacy_event.bind_to_enclosing"),
2088 Variadic::Boolean(true)));
2089 EXPECT_TRUE(HasArg(1u, storage_->InternString("legacy_event.flow_direction"),
2090 Variadic::String(storage_->InternString("inout"))));
Lalit Maganti47bc3d62020-01-15 16:21:22 +00002091 EXPECT_TRUE(HasArg(1u, debug_an_1, Variadic::UnsignedInteger(10u)));
Eric Secklerb7e26332019-07-19 12:46:17 +01002092}
2093
Eric Seckler15ea5df2019-10-14 13:54:07 +01002094TEST_F(ProtoTraceParserTest, TrackEventLegacyTimestampsWithClockSnapshot) {
2095 context_.sorter.reset(new TraceSorter(
2096 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
2097
Eric Seckler9cadb3a2019-11-14 01:38:33 +00002098 clock_->AddSnapshot(
2099 {{protos::pbzero::ClockSnapshot::Clock::BOOTTIME, 0},
2100 {protos::pbzero::ClockSnapshot::Clock::MONOTONIC, 1000000}});
Eric Seckler15ea5df2019-10-14 13:54:07 +01002101
2102 {
2103 auto* packet = trace_.add_packet();
2104 packet->set_trusted_packet_sequence_id(1);
2105 packet->set_incremental_state_cleared(true);
2106 auto* thread_desc = packet->set_thread_descriptor();
2107 thread_desc->set_pid(15);
2108 thread_desc->set_tid(16);
2109 thread_desc->set_reference_timestamp_us(1000); // MONOTONIC.
2110 }
2111 {
2112 auto* packet = trace_.add_packet();
2113 packet->set_trusted_packet_sequence_id(1);
2114 auto* event = packet->set_track_event();
2115 event->set_timestamp_delta_us(10); // absolute: 1010 (mon), 10 (boot).
2116 event->add_category_iids(1);
2117 event->set_type(protos::pbzero::TrackEvent::TYPE_SLICE_BEGIN);
2118 auto* legacy_event = event->set_legacy_event();
2119 legacy_event->set_name_iid(1);
2120 }
2121
2122 Tokenize();
2123
Eric Seckler3183c6d2020-01-14 15:45:20 +00002124 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillRepeatedly(Return(1));
Eric Seckler15ea5df2019-10-14 13:54:07 +01002125
Lalit Magantieac7fff2020-01-10 16:42:54 +00002126 tables::ThreadTable::Row row(16);
2127 row.upid = 1u;
2128 storage_->mutable_thread_table()->Insert(row);
Eric Seckler15ea5df2019-10-14 13:54:07 +01002129
Lalit Magantib0e11f62020-01-02 14:17:58 +00002130 constexpr TrackId track{0u};
Eric Seckler15ea5df2019-10-14 13:54:07 +01002131 InSequence in_sequence; // Below slices should be sorted by timestamp.
2132
2133 // Timestamp should be adjusted to trace time (BOOTTIME).
Lalit Magantic7ea02e2019-12-12 14:06:49 +00002134 EXPECT_CALL(*slice_, Begin(10000, track, kNullStringId, kNullStringId, _));
Eric Seckler15ea5df2019-10-14 13:54:07 +01002135
2136 context_.sorter->ExtractEventsForced();
2137}
2138
Eric Seckler6f263fd2019-10-24 16:48:24 +01002139TEST_F(ProtoTraceParserTest, ParseEventWithClockIdButWithoutClockSnapshot) {
2140 context_.sorter.reset(new TraceSorter(
2141 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
2142
2143 {
2144 auto* packet = trace_.add_packet();
2145 packet->set_timestamp(1000);
2146 packet->set_timestamp_clock_id(3);
2147 packet->set_trusted_packet_sequence_id(1);
2148 auto* bundle = packet->set_chrome_events();
2149 auto* metadata = bundle->add_metadata();
2150 metadata->set_name("test");
2151 metadata->set_int_value(23);
2152 }
2153
2154 util::Status status = Tokenize();
2155 EXPECT_TRUE(status.ok());
2156 context_.sorter->ExtractEventsForced();
2157
2158 // Metadata should have created a raw event.
Lalit Maganti679b29d2020-01-13 13:26:28 +00002159 const auto& raw_table = storage_->raw_table();
2160 EXPECT_EQ(raw_table.row_count(), 1u);
Eric Seckler6f263fd2019-10-24 16:48:24 +01002161}
2162
Mikhail Khokhlovca34df22019-08-07 16:50:01 +01002163TEST_F(ProtoTraceParserTest, ParseChromeMetadataEventIntoRawTable) {
2164 static const char kStringName[] = "string_name";
2165 static const char kStringValue[] = "string_value";
2166 static const char kIntName[] = "int_name";
2167 static const int kIntValue = 123;
2168
2169 context_.sorter.reset(new TraceSorter(
2170 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
2171
2172 {
2173 auto* packet = trace_.add_packet();
Eric Seckler6f263fd2019-10-24 16:48:24 +01002174 packet->set_timestamp(1000);
2175 packet->set_timestamp_clock_id(3);
Mikhail Khokhlovca34df22019-08-07 16:50:01 +01002176 packet->set_trusted_packet_sequence_id(1);
2177 auto* bundle = packet->set_chrome_events();
2178 auto* metadata = bundle->add_metadata();
2179 metadata->set_name(kStringName);
2180 metadata->set_string_value(kStringValue);
2181 metadata = bundle->add_metadata();
2182 metadata->set_name(kIntName);
2183 metadata->set_int_value(kIntValue);
2184 }
2185
2186 Tokenize();
2187 context_.sorter->ExtractEventsForced();
2188
Lalit Maganti679b29d2020-01-13 13:26:28 +00002189 // Verify raw_table and args contents.
2190 const auto& raw_table = storage_->raw_table();
2191 EXPECT_EQ(raw_table.row_count(), 1u);
2192 EXPECT_EQ(raw_table.name()[0],
Mikhail Khokhlovca34df22019-08-07 16:50:01 +01002193 storage_->InternString("chrome_event.metadata"));
Lalit Maganti679b29d2020-01-13 13:26:28 +00002194 EXPECT_EQ(raw_table.arg_set_id()[0], 1u);
Mikhail Khokhlovca34df22019-08-07 16:50:01 +01002195
Lalit Maganti1908e262020-01-09 14:33:19 +00002196 EXPECT_EQ(storage_->arg_table().row_count(), 2u);
Mikhail Khokhlovca34df22019-08-07 16:50:01 +01002197 EXPECT_TRUE(HasArg(1u, storage_->InternString(kStringName),
2198 Variadic::String(storage_->InternString(kStringValue))));
2199 EXPECT_TRUE(HasArg(1u, storage_->InternString(kIntName),
2200 Variadic::Integer(kIntValue)));
2201}
2202
Mikhail Khokhlovfd746552019-08-15 14:54:29 +01002203TEST_F(ProtoTraceParserTest, ParseChromeLegacyFtraceIntoRawTable) {
2204 static const char kDataPart0[] = "aaa";
2205 static const char kDataPart1[] = "bbb";
2206 static const char kFullData[] = "aaabbb";
2207
2208 context_.sorter.reset(new TraceSorter(
2209 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
2210
2211 {
2212 auto* packet = trace_.add_packet();
2213 packet->set_trusted_packet_sequence_id(1);
2214 auto* bundle = packet->set_chrome_events();
2215 bundle->add_legacy_ftrace_output(kDataPart0);
2216 bundle->add_legacy_ftrace_output(kDataPart1);
2217 }
2218
2219 Tokenize();
2220
2221 context_.sorter->ExtractEventsForced();
2222
Lalit Maganti679b29d2020-01-13 13:26:28 +00002223 // Verify raw_table and args contents.
2224 const auto& raw_table = storage_->raw_table();
2225 EXPECT_EQ(raw_table.row_count(), 1u);
2226 EXPECT_EQ(raw_table.name()[0],
Mikhail Khokhlovfd746552019-08-15 14:54:29 +01002227 storage_->InternString("chrome_event.legacy_system_trace"));
Lalit Maganti679b29d2020-01-13 13:26:28 +00002228 EXPECT_EQ(raw_table.arg_set_id()[0], 1u);
Mikhail Khokhlovfd746552019-08-15 14:54:29 +01002229
Lalit Maganti1908e262020-01-09 14:33:19 +00002230 EXPECT_EQ(storage_->arg_table().row_count(), 1u);
Mikhail Khokhlovfd746552019-08-15 14:54:29 +01002231 EXPECT_TRUE(HasArg(1u, storage_->InternString("data"),
2232 Variadic::String(storage_->InternString(kFullData))));
2233}
2234
2235TEST_F(ProtoTraceParserTest, ParseChromeLegacyJsonIntoRawTable) {
2236 static const char kUserTraceEvent[] = "{\"user\":1}";
2237
2238 context_.sorter.reset(new TraceSorter(
2239 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
2240
2241 {
2242 auto* packet = trace_.add_packet();
2243 packet->set_trusted_packet_sequence_id(1);
2244 auto* bundle = packet->set_chrome_events();
2245 auto* user_trace = bundle->add_legacy_json_trace();
2246 user_trace->set_type(protos::pbzero::ChromeLegacyJsonTrace::USER_TRACE);
2247 user_trace->set_data(kUserTraceEvent);
2248 }
2249
2250 Tokenize();
2251
2252 context_.sorter->ExtractEventsForced();
2253
Lalit Maganti679b29d2020-01-13 13:26:28 +00002254 // Verify raw_table and args contents.
2255 const auto& raw_table = storage_->raw_table();
2256 EXPECT_EQ(raw_table.row_count(), 1u);
2257 EXPECT_EQ(raw_table.name()[0],
Mikhail Khokhlovfd746552019-08-15 14:54:29 +01002258 storage_->InternString("chrome_event.legacy_user_trace"));
Lalit Maganti679b29d2020-01-13 13:26:28 +00002259 EXPECT_EQ(raw_table.arg_set_id()[0], 1u);
Mikhail Khokhlovfd746552019-08-15 14:54:29 +01002260
Lalit Maganti1908e262020-01-09 14:33:19 +00002261 EXPECT_EQ(storage_->arg_table().row_count(), 1u);
Eric Seckler13b84b32019-10-04 12:00:38 +01002262 EXPECT_TRUE(
2263 HasArg(1u, storage_->InternString("data"),
2264 Variadic::String(storage_->InternString(kUserTraceEvent))));
Mikhail Khokhlovfd746552019-08-15 14:54:29 +01002265}
2266
Mikhail Khokhlovb1fe42a2019-05-23 13:58:05 +01002267TEST_F(ProtoTraceParserTest, LoadChromeBenchmarkMetadata) {
2268 static const char kName[] = "name";
Ryan Savitski0476ee92019-07-09 14:29:33 +01002269 static const char kTag1[] = "tag1";
2270 static const char kTag2[] = "tag2";
Mikhail Khokhlovb1fe42a2019-05-23 13:58:05 +01002271
Mikhail Khokhlovb1fe42a2019-05-23 13:58:05 +01002272 context_.sorter.reset(new TraceSorter(
2273 &context_, std::numeric_limits<int64_t>::max() /*window size*/));
2274
2275 auto* metadata = trace_.add_packet()->set_chrome_benchmark_metadata();
2276 metadata->set_benchmark_name(kName);
2277 metadata->add_story_tags(kTag1);
2278 metadata->add_story_tags(kTag2);
2279
2280 Tokenize();
2281
Lalit Maganti47bc3d62020-01-15 16:21:22 +00002282 StringId name_1 = storage_->InternString(kName);
2283 StringId tag_1 = storage_->InternString(kTag1);
2284 StringId tag_2 = storage_->InternString(kTag2);
Mikhail Khokhlovb1fe42a2019-05-23 13:58:05 +01002285
Lalit Magantiededb0e2020-01-08 12:50:34 +00002286 StringId benchmark_id = *storage_->string_pool().GetId(
2287 metadata::kNames[metadata::benchmark_name]);
2288 StringId tags_id = *storage_->string_pool().GetId(
2289 metadata::kNames[metadata::benchmark_story_tags]);
2290
Mikhail Khokhlovb1fe42a2019-05-23 13:58:05 +01002291 context_.sorter->ExtractEventsForced();
Ryan Savitski0476ee92019-07-09 14:29:33 +01002292
Lalit Magantiededb0e2020-01-08 12:50:34 +00002293 const auto& meta_keys = storage_->metadata_table().name();
2294 const auto& meta_values = storage_->metadata_table().str_value();
2295 EXPECT_EQ(storage_->metadata_table().row_count(), 3u);
2296
2297 std::vector<std::pair<StringId, StringId>> meta_entries;
2298 for (uint32_t i = 0; i < storage_->metadata_table().row_count(); i++) {
Ryan Savitski0476ee92019-07-09 14:29:33 +01002299 meta_entries.emplace_back(std::make_pair(meta_keys[i], meta_values[i]));
2300 }
Lalit Maganti47bc3d62020-01-15 16:21:22 +00002301 EXPECT_THAT(meta_entries,
2302 UnorderedElementsAreArray({std::make_pair(benchmark_id, name_1),
2303 std::make_pair(tags_id, tag_1),
2304 std::make_pair(tags_id, tag_2)}));
Ryan Savitski0476ee92019-07-09 14:29:33 +01002305}
2306
2307TEST_F(ProtoTraceParserTest, AndroidPackagesList) {
2308 auto* packet = trace_.add_packet();
2309 auto* pkg_list = packet->set_packages_list();
2310
2311 pkg_list->set_read_error(false);
2312 pkg_list->set_parse_error(true);
2313 {
2314 auto* pkg = pkg_list->add_packages();
2315 pkg->set_name("com.test.app");
2316 pkg->set_uid(1000);
2317 pkg->set_debuggable(false);
2318 pkg->set_profileable_from_shell(true);
2319 pkg->set_version_code(42);
2320 }
2321 {
2322 auto* pkg = pkg_list->add_packages();
2323 pkg->set_name("com.test.app2");
2324 pkg->set_uid(1001);
2325 pkg->set_debuggable(false);
2326 pkg->set_profileable_from_shell(false);
2327 pkg->set_version_code(43);
2328 }
2329
2330 Tokenize();
2331
2332 // Packet-level errors reflected in stats storage.
2333 const auto& stats = context_.storage->stats();
2334 EXPECT_FALSE(stats[stats::packages_list_has_read_errors].value);
2335 EXPECT_TRUE(stats[stats::packages_list_has_parse_errors].value);
2336
2337 // Expect two metadata rows, each with an int_value of a separate arg set id.
2338 // The relevant arg sets have the info about the packages. To simplify test
2339 // structure, make an assumption that metadata storage is filled in in the
2340 // FIFO order of seen packages.
Lalit Maganti1908e262020-01-09 14:33:19 +00002341 const auto& args = context_.storage->arg_table();
Lalit Magantiededb0e2020-01-08 12:50:34 +00002342 const auto& metadata = context_.storage->metadata_table();
Ryan Savitski0476ee92019-07-09 14:29:33 +01002343
Lalit Magantiededb0e2020-01-08 12:50:34 +00002344 Table package_list = metadata.Filter(
2345 {metadata.name().eq(metadata::kNames[metadata::android_packages_list])});
2346 ASSERT_EQ(package_list.row_count(), 2u);
Ryan Savitski0476ee92019-07-09 14:29:33 +01002347
Lalit Magantiededb0e2020-01-08 12:50:34 +00002348 const Column* int_value = package_list.GetColumnByName("int_value");
2349 uint32_t first_set_id = static_cast<uint32_t>(int_value->Get(0).long_value);
2350 uint32_t second_set_id = static_cast<uint32_t>(int_value->Get(1).long_value);
Ryan Savitski0476ee92019-07-09 14:29:33 +01002351
2352 // helper to look up arg values
2353 auto find_arg = [&args, this](ArgSetId set_id, const char* arg_name) {
Lalit Maganti1908e262020-01-09 14:33:19 +00002354 for (uint32_t i = 0; i < args.row_count(); i++) {
2355 if (args.arg_set_id()[i] == set_id &&
2356 args.key()[i] == storage_->InternString(arg_name))
2357 return storage_->GetArgValue(i);
Ryan Savitski0476ee92019-07-09 14:29:33 +01002358 }
2359 PERFETTO_FATAL("Didn't find expected argument");
2360 };
2361
2362 auto first_name_id = find_arg(first_set_id, "name").string_value;
2363 EXPECT_STREQ(storage_->GetString(first_name_id).c_str(), "com.test.app");
Ryan Savitski944f7de2019-07-11 18:05:55 +01002364 EXPECT_EQ(find_arg(first_set_id, "uid").uint_value, 1000u);
Ryan Savitskiafdf0f82019-07-11 12:49:44 +01002365 EXPECT_EQ(find_arg(first_set_id, "debuggable").bool_value, false);
2366 EXPECT_EQ(find_arg(first_set_id, "profileable_from_shell").bool_value, true);
Ryan Savitski0476ee92019-07-09 14:29:33 +01002367 EXPECT_EQ(find_arg(first_set_id, "version_code").int_value, 42);
2368
2369 auto second_name_id = find_arg(second_set_id, "name").string_value;
2370 EXPECT_STREQ(storage_->GetString(second_name_id).c_str(), "com.test.app2");
Ryan Savitski944f7de2019-07-11 18:05:55 +01002371 EXPECT_EQ(find_arg(second_set_id, "uid").uint_value, 1001u);
Ryan Savitskiafdf0f82019-07-11 12:49:44 +01002372 EXPECT_EQ(find_arg(second_set_id, "debuggable").bool_value, false);
2373 EXPECT_EQ(find_arg(second_set_id, "profileable_from_shell").bool_value,
2374 false);
Ryan Savitski0476ee92019-07-09 14:29:33 +01002375 EXPECT_EQ(find_arg(second_set_id, "version_code").int_value, 43);
Mikhail Khokhlovb1fe42a2019-05-23 13:58:05 +01002376}
2377
Oystein Eftevaag7f64c102019-08-29 10:27:31 -07002378TEST_F(ProtoTraceParserTest, ParseCPUProfileSamplesIntoTable) {
2379 {
2380 auto* packet = trace_.add_packet();
2381 packet->set_trusted_packet_sequence_id(1);
2382 packet->set_incremental_state_cleared(true);
2383
2384 auto* thread_desc = packet->set_thread_descriptor();
2385 thread_desc->set_pid(15);
2386 thread_desc->set_tid(16);
2387 thread_desc->set_reference_timestamp_us(1);
2388 thread_desc->set_reference_thread_time_us(2);
2389
2390 auto* interned_data = packet->set_interned_data();
2391
2392 auto mapping = interned_data->add_mappings();
2393 mapping->set_iid(1);
Oystein Eftevaagaa944212020-01-22 14:32:47 -08002394 mapping->set_build_id(1);
2395
2396 auto build_id = interned_data->add_build_ids();
2397 build_id->set_iid(1);
2398 build_id->set_str("3BBCFBD372448A727265C3E7C4D954F91");
Oystein Eftevaag7f64c102019-08-29 10:27:31 -07002399
2400 auto frame = interned_data->add_frames();
2401 frame->set_iid(1);
2402 frame->set_rel_pc(0x42);
2403 frame->set_mapping_id(1);
2404
2405 auto frame2 = interned_data->add_frames();
2406 frame2->set_iid(2);
2407 frame2->set_rel_pc(0x4242);
2408 frame2->set_mapping_id(1);
2409
2410 auto callstack = interned_data->add_callstacks();
2411 callstack->set_iid(1);
2412 callstack->add_frame_ids(1);
2413
2414 auto callstack2 = interned_data->add_callstacks();
2415 callstack2->set_iid(42);
2416 callstack2->add_frame_ids(2);
2417 }
2418
2419 {
2420 auto* packet = trace_.add_packet();
2421 packet->set_trusted_packet_sequence_id(1);
2422
2423 auto* samples = packet->set_streaming_profile_packet();
2424 samples->add_callstack_iid(42);
2425 samples->add_timestamp_delta_us(10);
2426
2427 samples->add_callstack_iid(1);
2428 samples->add_timestamp_delta_us(15);
2429 }
2430
2431 {
2432 auto* packet = trace_.add_packet();
2433 packet->set_trusted_packet_sequence_id(1);
2434 auto* samples = packet->set_streaming_profile_packet();
2435
2436 samples->add_callstack_iid(42);
2437 samples->add_timestamp_delta_us(42);
2438 }
2439
2440 EXPECT_CALL(*process_, UpdateThread(16, 15))
Oystein Eftevaag7f64c102019-08-29 10:27:31 -07002441 .WillRepeatedly(Return(1));
2442
2443 Tokenize();
2444
2445 // Verify cpu_profile_samples.
Lalit Maganti0fd14ef2019-12-18 18:18:44 +00002446 const auto& samples = storage_->cpu_profile_stack_sample_table();
2447 EXPECT_EQ(samples.row_count(), 3u);
Oystein Eftevaag7f64c102019-08-29 10:27:31 -07002448
Oystein Eftevaag65ab9662020-01-14 15:09:39 -08002449 EXPECT_EQ(samples.ts()[0], 11000);
Lalit Maganti3f37ad52020-01-30 11:56:47 +00002450 EXPECT_EQ(samples.callsite_id()[0], CallsiteId{0});
Lalit Maganti0fd14ef2019-12-18 18:18:44 +00002451 EXPECT_EQ(samples.utid()[0], 1u);
Oystein Eftevaag7f64c102019-08-29 10:27:31 -07002452
Oystein Eftevaag65ab9662020-01-14 15:09:39 -08002453 EXPECT_EQ(samples.ts()[1], 26000);
Lalit Maganti3f37ad52020-01-30 11:56:47 +00002454 EXPECT_EQ(samples.callsite_id()[1], CallsiteId{1});
Lalit Maganti0fd14ef2019-12-18 18:18:44 +00002455 EXPECT_EQ(samples.utid()[1], 1u);
Oystein Eftevaag7f64c102019-08-29 10:27:31 -07002456
Oystein Eftevaag65ab9662020-01-14 15:09:39 -08002457 EXPECT_EQ(samples.ts()[2], 68000);
Lalit Maganti3f37ad52020-01-30 11:56:47 +00002458 EXPECT_EQ(samples.callsite_id()[2], CallsiteId{0});
Lalit Maganti0fd14ef2019-12-18 18:18:44 +00002459 EXPECT_EQ(samples.utid()[2], 1u);
Oystein Eftevaagaa944212020-01-22 14:32:47 -08002460
2461 // Breakpad build_ids should not be modified/mangled.
2462 ASSERT_STREQ(
2463 context_.storage
2464 ->GetString(storage_->stack_profile_mapping_table().build_id()[0])
2465 .c_str(),
2466 "3BBCFBD372448A727265C3E7C4D954F91");
Oystein Eftevaag7f64c102019-08-29 10:27:31 -07002467}
2468
Eric Seckler44eeb882020-02-03 11:31:12 +00002469TEST_F(ProtoTraceParserTest, CPUProfileSamplesTimestampsAreClockMonotonic) {
2470 {
2471 auto* packet = trace_.add_packet();
2472 packet->set_trusted_packet_sequence_id(0);
2473
2474 // 1000 us monotonic == 10000 us boottime.
2475 auto* clock_snapshot = packet->set_clock_snapshot();
2476 auto* clock_boot = clock_snapshot->add_clocks();
2477 clock_boot->set_clock_id(protos::pbzero::ClockSnapshot::Clock::BOOTTIME);
2478 clock_boot->set_timestamp(10000000);
2479 auto* clock_monotonic = clock_snapshot->add_clocks();
2480 clock_monotonic->set_clock_id(
2481 protos::pbzero::ClockSnapshot::Clock::MONOTONIC);
2482 clock_monotonic->set_timestamp(1000000);
2483 }
2484
2485 {
2486 auto* packet = trace_.add_packet();
2487 packet->set_trusted_packet_sequence_id(1);
2488 packet->set_incremental_state_cleared(true);
2489
2490 auto* thread_desc = packet->set_thread_descriptor();
2491 thread_desc->set_pid(15);
2492 thread_desc->set_tid(16);
2493 thread_desc->set_reference_timestamp_us(1000);
2494 thread_desc->set_reference_thread_time_us(2000);
2495
2496 auto* interned_data = packet->set_interned_data();
2497
2498 auto mapping = interned_data->add_mappings();
2499 mapping->set_iid(1);
2500 mapping->set_build_id(1);
2501
2502 auto build_id = interned_data->add_build_ids();
2503 build_id->set_iid(1);
2504 build_id->set_str("3BBCFBD372448A727265C3E7C4D954F91");
2505
2506 auto frame = interned_data->add_frames();
2507 frame->set_iid(1);
2508 frame->set_rel_pc(0x42);
2509 frame->set_mapping_id(1);
2510
2511 auto callstack = interned_data->add_callstacks();
2512 callstack->set_iid(1);
2513 callstack->add_frame_ids(1);
2514 }
2515
2516 {
2517 auto* packet = trace_.add_packet();
2518 packet->set_trusted_packet_sequence_id(1);
2519
2520 auto* samples = packet->set_streaming_profile_packet();
2521 samples->add_callstack_iid(1);
2522 samples->add_timestamp_delta_us(15);
2523 }
2524
2525 EXPECT_CALL(*process_, UpdateThread(16, 15)).WillRepeatedly(Return(1));
2526
2527 Tokenize();
2528
2529 const auto& samples = storage_->cpu_profile_stack_sample_table();
2530 EXPECT_EQ(samples.row_count(), 1u);
2531
2532 // Should have been translated to boottime, i.e. 10015 us absolute.
2533 EXPECT_EQ(samples.ts()[0], 10015000);
2534 EXPECT_EQ(samples.callsite_id()[0], CallsiteId{0});
2535 EXPECT_EQ(samples.utid()[0], 1u);
2536}
2537
Lalit Maganti93b76362018-06-01 03:03:58 +01002538} // namespace
2539} // namespace trace_processor
2540} // namespace perfetto