1 /*
2 * Copyright (C) 2018 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17 #include <algorithm>
18 #include <map>
19 #include <random>
20 #include <string>
21
22 #include "perfetto/base/logging.h"
23 #include "perfetto/ext/base/optional.h"
24 #include "perfetto/ext/base/scoped_file.h"
25 #include "perfetto/trace_processor/trace_processor.h"
26 #include "protos/perfetto/common/descriptor.pbzero.h"
27 #include "protos/perfetto/trace_processor/trace_processor.pbzero.h"
28
29 #include "src/base/test/utils.h"
30 #include "test/gtest_and_gmock.h"
31
32 namespace perfetto {
33 namespace trace_processor {
34 namespace {
35
36 constexpr size_t kMaxChunkSize = 4 * 1024 * 1024;
37
38 class TraceProcessorIntegrationTest : public ::testing::Test {
39 public:
TraceProcessorIntegrationTest()40 TraceProcessorIntegrationTest()
41 : processor_(TraceProcessor::CreateInstance(Config())) {}
42
43 protected:
LoadTrace(const char * name,size_t min_chunk_size=512)44 util::Status LoadTrace(const char* name, size_t min_chunk_size = 512) {
45 EXPECT_LE(min_chunk_size, kMaxChunkSize);
46 base::ScopedFstream f(fopen(
47 base::GetTestDataPath(std::string("test/data/") + name).c_str(), "rb"));
48 std::minstd_rand0 rnd_engine(0);
49 std::uniform_int_distribution<size_t> dist(min_chunk_size, kMaxChunkSize);
50 while (!feof(*f)) {
51 size_t chunk_size = dist(rnd_engine);
52 std::unique_ptr<uint8_t[]> buf(new uint8_t[chunk_size]);
53 auto rsize = fread(reinterpret_cast<char*>(buf.get()), 1, chunk_size, *f);
54 auto status = processor_->Parse(std::move(buf), rsize);
55 if (!status.ok())
56 return status;
57 }
58 processor_->NotifyEndOfFile();
59 return util::OkStatus();
60 }
61
Query(const std::string & query)62 Iterator Query(const std::string& query) {
63 return processor_->ExecuteQuery(query.c_str());
64 }
65
Processor()66 TraceProcessor* Processor() { return processor_.get(); }
67
RestoreInitialTables()68 size_t RestoreInitialTables() { return processor_->RestoreInitialTables(); }
69
70 private:
71 std::unique_ptr<TraceProcessor> processor_;
72 };
73
TEST_F(TraceProcessorIntegrationTest,AndroidSchedAndPs)74 TEST_F(TraceProcessorIntegrationTest, AndroidSchedAndPs) {
75 ASSERT_TRUE(LoadTrace("android_sched_and_ps.pb").ok());
76 auto it = Query(
77 "select count(*), max(ts) - min(ts) from sched "
78 "where dur != 0 and utid != 0");
79 ASSERT_TRUE(it.Next());
80 ASSERT_EQ(it.Get(0).type, SqlValue::kLong);
81 ASSERT_EQ(it.Get(0).long_value, 139787);
82 ASSERT_EQ(it.Get(1).type, SqlValue::kLong);
83 ASSERT_EQ(it.Get(1).long_value, 19684308497);
84 ASSERT_FALSE(it.Next());
85 }
86
TEST_F(TraceProcessorIntegrationTest,TraceBounds)87 TEST_F(TraceProcessorIntegrationTest, TraceBounds) {
88 ASSERT_TRUE(LoadTrace("android_sched_and_ps.pb").ok());
89 auto it = Query("select start_ts, end_ts from trace_bounds");
90 ASSERT_TRUE(it.Next());
91 ASSERT_EQ(it.Get(0).type, SqlValue::kLong);
92 ASSERT_EQ(it.Get(0).long_value, 81473009948313);
93 ASSERT_EQ(it.Get(1).type, SqlValue::kLong);
94 ASSERT_EQ(it.Get(1).long_value, 81492700784311);
95 ASSERT_FALSE(it.Next());
96 }
97
98 // Tests that the duration of the last slice is accounted in the computation
99 // of the trace boundaries. Linux ftraces tend to hide this problem because
100 // after the last sched_switch there's always a "wake" event which causes the
101 // raw table to fix the bounds.
TEST_F(TraceProcessorIntegrationTest,TraceBoundsUserspaceOnly)102 TEST_F(TraceProcessorIntegrationTest, TraceBoundsUserspaceOnly) {
103 ASSERT_TRUE(LoadTrace("sfgate.json").ok());
104 auto it = Query("select start_ts, end_ts from trace_bounds");
105 ASSERT_TRUE(it.Next());
106 ASSERT_EQ(it.Get(0).type, SqlValue::kLong);
107 ASSERT_EQ(it.Get(0).long_value, 2213649212614000);
108 ASSERT_EQ(it.Get(1).type, SqlValue::kLong);
109 ASSERT_EQ(it.Get(1).long_value, 2213689745140000);
110 ASSERT_FALSE(it.Next());
111 }
112
TEST_F(TraceProcessorIntegrationTest,Hash)113 TEST_F(TraceProcessorIntegrationTest, Hash) {
114 auto it = Query("select HASH()");
115 ASSERT_TRUE(it.Next());
116 ASSERT_EQ(it.Get(0).long_value, static_cast<int64_t>(0xcbf29ce484222325));
117
118 it = Query("select HASH('test')");
119 ASSERT_TRUE(it.Next());
120 ASSERT_EQ(it.Get(0).long_value, static_cast<int64_t>(0xf9e6e6ef197c2b25));
121
122 it = Query("select HASH('test', 1)");
123 ASSERT_TRUE(it.Next());
124 ASSERT_EQ(it.Get(0).long_value, static_cast<int64_t>(0xa9cb070fdc15f7a4));
125 }
126
127 #if PERFETTO_BUILDFLAG(PERFETTO_OS_WIN)
128 #define MAYBE_Demangle DISABLED_Demangle
129 #else
130 #define MAYBE_Demangle Demangle
131 #endif
TEST_F(TraceProcessorIntegrationTest,MAYBE_Demangle)132 TEST_F(TraceProcessorIntegrationTest, MAYBE_Demangle) {
133 auto it = Query("select DEMANGLE('_Znwm')");
134 ASSERT_TRUE(it.Next());
135 ASSERT_STRCASEEQ(it.Get(0).string_value, "operator new(unsigned long)");
136
137 it = Query("select DEMANGLE('_ZN3art6Thread14CreateCallbackEPv')");
138 ASSERT_TRUE(it.Next());
139 ASSERT_STRCASEEQ(it.Get(0).string_value,
140 "art::Thread::CreateCallback(void*)");
141
142 it = Query("select DEMANGLE('test')");
143 ASSERT_TRUE(it.Next());
144 ASSERT_TRUE(it.Get(0).is_null());
145 }
146
147 #if PERFETTO_BUILDFLAG(PERFETTO_TP_JSON)
TEST_F(TraceProcessorIntegrationTest,Sfgate)148 TEST_F(TraceProcessorIntegrationTest, Sfgate) {
149 ASSERT_TRUE(LoadTrace("sfgate.json", strlen("{\"traceEvents\":[")).ok());
150 auto it = Query(
151 "select count(*), max(ts) - min(ts) "
152 "from slice s inner join thread_track t "
153 "on s.track_id = t.id where utid != 0");
154 ASSERT_TRUE(it.Next());
155 ASSERT_EQ(it.Get(0).type, SqlValue::kLong);
156 ASSERT_EQ(it.Get(0).long_value, 39828);
157 ASSERT_EQ(it.Get(1).type, SqlValue::kLong);
158 ASSERT_EQ(it.Get(1).long_value, 40532506000);
159 ASSERT_FALSE(it.Next());
160 }
161
TEST_F(TraceProcessorIntegrationTest,UnsortedTrace)162 TEST_F(TraceProcessorIntegrationTest, UnsortedTrace) {
163 ASSERT_TRUE(
164 LoadTrace("unsorted_trace.json", strlen("{\"traceEvents\":[")).ok());
165 auto it = Query("select ts, depth from slice order by ts");
166 ASSERT_TRUE(it.Next());
167 ASSERT_EQ(it.Get(0).type, SqlValue::kLong);
168 ASSERT_EQ(it.Get(0).long_value, 50000);
169 ASSERT_EQ(it.Get(1).type, SqlValue::kLong);
170 ASSERT_EQ(it.Get(1).long_value, 0);
171 ASSERT_TRUE(it.Next());
172 ASSERT_EQ(it.Get(0).type, SqlValue::kLong);
173 ASSERT_EQ(it.Get(0).long_value, 100000);
174 ASSERT_EQ(it.Get(1).type, SqlValue::kLong);
175 ASSERT_EQ(it.Get(1).long_value, 1);
176 ASSERT_FALSE(it.Next());
177 }
178
TEST_F(TraceProcessorIntegrationTest,SerializeMetricDescriptors)179 TEST_F(TraceProcessorIntegrationTest, SerializeMetricDescriptors) {
180 std::vector<uint8_t> desc_set_bytes = Processor()->GetMetricDescriptors();
181 protos::pbzero::DescriptorSet::Decoder desc_set(desc_set_bytes.data(),
182 desc_set_bytes.size());
183
184 ASSERT_TRUE(desc_set.has_descriptors());
185 int trace_metrics_count = 0;
186 for (auto desc = desc_set.descriptors(); desc; ++desc) {
187 protos::pbzero::DescriptorProto::Decoder proto_desc(*desc);
188 if (proto_desc.name().ToStdString() == ".perfetto.protos.TraceMetrics") {
189 ASSERT_TRUE(proto_desc.has_field());
190 trace_metrics_count++;
191 }
192 }
193
194 // There should be exactly one definition of TraceMetrics. This can be not
195 // true if we're not deduping descriptors properly.
196 ASSERT_EQ(trace_metrics_count, 1);
197 }
198
TEST_F(TraceProcessorIntegrationTest,ComputeMetricsFormatted)199 TEST_F(TraceProcessorIntegrationTest, ComputeMetricsFormatted) {
200 std::string metric_output;
201 util::Status status = Processor()->ComputeMetricText(
202 std::vector<std::string>{"test_chrome_metric"},
203 TraceProcessor::MetricResultFormat::kProtoText, &metric_output);
204 ASSERT_TRUE(status.ok());
205 ASSERT_EQ(metric_output,
206 "test_chrome_metric: {\n"
207 " test_value: 1\n"
208 "}");
209 }
210
211 // TODO(hjd): Add trace to test_data.
TEST_F(TraceProcessorIntegrationTest,DISABLED_AndroidBuildTrace)212 TEST_F(TraceProcessorIntegrationTest, DISABLED_AndroidBuildTrace) {
213 ASSERT_TRUE(LoadTrace("android_build_trace.json", strlen("[\n{")).ok());
214 }
215
TEST_F(TraceProcessorIntegrationTest,DISABLED_Clusterfuzz14357)216 TEST_F(TraceProcessorIntegrationTest, DISABLED_Clusterfuzz14357) {
217 ASSERT_FALSE(LoadTrace("clusterfuzz_14357", 4096).ok());
218 }
219 #endif // PERFETTO_BUILDFLAG(PERFETTO_TP_JSON)
220
TEST_F(TraceProcessorIntegrationTest,Clusterfuzz14730)221 TEST_F(TraceProcessorIntegrationTest, Clusterfuzz14730) {
222 ASSERT_TRUE(LoadTrace("clusterfuzz_14730", 4096).ok());
223 }
224
TEST_F(TraceProcessorIntegrationTest,Clusterfuzz14753)225 TEST_F(TraceProcessorIntegrationTest, Clusterfuzz14753) {
226 ASSERT_TRUE(LoadTrace("clusterfuzz_14753", 4096).ok());
227 }
228
TEST_F(TraceProcessorIntegrationTest,Clusterfuzz14762)229 TEST_F(TraceProcessorIntegrationTest, Clusterfuzz14762) {
230 ASSERT_TRUE(LoadTrace("clusterfuzz_14762", 4096 * 1024).ok());
231 auto it = Query("select sum(value) from stats where severity = 'error';");
232 ASSERT_TRUE(it.Next());
233 ASSERT_GT(it.Get(0).long_value, 0);
234 }
235
TEST_F(TraceProcessorIntegrationTest,Clusterfuzz14767)236 TEST_F(TraceProcessorIntegrationTest, Clusterfuzz14767) {
237 ASSERT_TRUE(LoadTrace("clusterfuzz_14767", 4096 * 1024).ok());
238 auto it = Query("select sum(value) from stats where severity = 'error';");
239 ASSERT_TRUE(it.Next());
240 ASSERT_GT(it.Get(0).long_value, 0);
241 }
242
TEST_F(TraceProcessorIntegrationTest,Clusterfuzz14799)243 TEST_F(TraceProcessorIntegrationTest, Clusterfuzz14799) {
244 ASSERT_TRUE(LoadTrace("clusterfuzz_14799", 4096 * 1024).ok());
245 auto it = Query("select sum(value) from stats where severity = 'error';");
246 ASSERT_TRUE(it.Next());
247 ASSERT_GT(it.Get(0).long_value, 0);
248 }
249
TEST_F(TraceProcessorIntegrationTest,Clusterfuzz15252)250 TEST_F(TraceProcessorIntegrationTest, Clusterfuzz15252) {
251 ASSERT_TRUE(LoadTrace("clusterfuzz_15252", 4096).ok());
252 }
253
TEST_F(TraceProcessorIntegrationTest,Clusterfuzz17805)254 TEST_F(TraceProcessorIntegrationTest, Clusterfuzz17805) {
255 // This trace is garbage but is detected as a systrace. However, it should
256 // still parse successfully as we try to be graceful with encountering random
257 // data in systrace as they can have arbitrary print events from the kernel.
258 ASSERT_TRUE(LoadTrace("clusterfuzz_17805", 4096).ok());
259 }
260
261 // Failing on DCHECKs during import because the traces aren't really valid.
262 #if PERFETTO_DCHECK_IS_ON()
263 #define MAYBE_Clusterfuzz20215 DISABLED_Clusterfuzz20215
264 #define MAYBE_Clusterfuzz20292 DISABLED_Clusterfuzz20292
265 #define MAYBE_Clusterfuzz21178 DISABLED_Clusterfuzz21178
266 #define MAYBE_Clusterfuzz21890 DISABLED_Clusterfuzz21890
267 #define MAYBE_Clusterfuzz23053 DISABLED_Clusterfuzz23053
268 #define MAYBE_Clusterfuzz28338 DISABLED_Clusterfuzz28338
269 #define MAYBE_Clusterfuzz28766 DISABLED_Clusterfuzz28766
270 #else // PERFETTO_DCHECK_IS_ON()
271 #define MAYBE_Clusterfuzz20215 Clusterfuzz20215
272 #define MAYBE_Clusterfuzz20292 Clusterfuzz20292
273 #define MAYBE_Clusterfuzz21178 Clusterfuzz21178
274 #define MAYBE_Clusterfuzz21890 Clusterfuzz21890
275 #define MAYBE_Clusterfuzz23053 Clusterfuzz23053
276 #define MAYBE_Clusterfuzz28338 Clusterfuzz28338
277 #define MAYBE_Clusterfuzz28766 Clusterfuzz28766
278 #endif // PERFETTO_DCHECK_IS_ON()
279
TEST_F(TraceProcessorIntegrationTest,MAYBE_Clusterfuzz20215)280 TEST_F(TraceProcessorIntegrationTest, MAYBE_Clusterfuzz20215) {
281 ASSERT_TRUE(LoadTrace("clusterfuzz_20215", 4096).ok());
282 }
283
TEST_F(TraceProcessorIntegrationTest,MAYBE_Clusterfuzz20292)284 TEST_F(TraceProcessorIntegrationTest, MAYBE_Clusterfuzz20292) {
285 ASSERT_FALSE(LoadTrace("clusterfuzz_20292", 4096).ok());
286 }
287
TEST_F(TraceProcessorIntegrationTest,MAYBE_Clusterfuzz21178)288 TEST_F(TraceProcessorIntegrationTest, MAYBE_Clusterfuzz21178) {
289 ASSERT_TRUE(LoadTrace("clusterfuzz_21178", 4096).ok());
290 }
291
TEST_F(TraceProcessorIntegrationTest,MAYBE_Clusterfuzz21890)292 TEST_F(TraceProcessorIntegrationTest, MAYBE_Clusterfuzz21890) {
293 ASSERT_FALSE(LoadTrace("clusterfuzz_21890", 4096).ok());
294 }
295
TEST_F(TraceProcessorIntegrationTest,MAYBE_Clusterfuzz23053)296 TEST_F(TraceProcessorIntegrationTest, MAYBE_Clusterfuzz23053) {
297 ASSERT_FALSE(LoadTrace("clusterfuzz_23053", 4096).ok());
298 }
299
TEST_F(TraceProcessorIntegrationTest,MAYBE_Clusterfuzz28338)300 TEST_F(TraceProcessorIntegrationTest, MAYBE_Clusterfuzz28338) {
301 ASSERT_TRUE(LoadTrace("clusterfuzz_28338", 4096).ok());
302 }
303
TEST_F(TraceProcessorIntegrationTest,MAYBE_Clusterfuzz28766)304 TEST_F(TraceProcessorIntegrationTest, MAYBE_Clusterfuzz28766) {
305 ASSERT_TRUE(LoadTrace("clusterfuzz_28766", 4096).ok());
306 }
307
TEST_F(TraceProcessorIntegrationTest,RestoreInitialTables)308 TEST_F(TraceProcessorIntegrationTest, RestoreInitialTables) {
309 ASSERT_TRUE(LoadTrace("android_sched_and_ps.pb").ok());
310
311 for (int repeat = 0; repeat < 3; repeat++) {
312 ASSERT_EQ(RestoreInitialTables(), 0u);
313
314 auto it = Query("CREATE TABLE user1(unused text);");
315 it.Next();
316 ASSERT_TRUE(it.Status().ok());
317
318 it = Query("CREATE TEMPORARY TABLE user2(unused text);");
319 it.Next();
320 ASSERT_TRUE(it.Status().ok());
321
322 it = Query("CREATE VIEW user3 AS SELECT * FROM stats;");
323 it.Next();
324 ASSERT_TRUE(it.Status().ok());
325
326 ASSERT_EQ(RestoreInitialTables(), 3u);
327 }
328 }
329
330 // This test checks that a ninja trace is tokenized properly even if read in
331 // small chunks of 1KB each. The values used in the test have been cross-checked
332 // with opening the same trace with ninjatracing + chrome://tracing.
TEST_F(TraceProcessorIntegrationTest,NinjaLog)333 TEST_F(TraceProcessorIntegrationTest, NinjaLog) {
334 ASSERT_TRUE(LoadTrace("ninja_log", 1024).ok());
335 auto it = Query("select count(*) from process where name like 'build';");
336 ASSERT_TRUE(it.Next());
337 ASSERT_EQ(it.Get(0).long_value, 2);
338
339 it = Query(
340 "select count(*) from thread left join process using(upid) where "
341 "thread.name like 'worker%' and process.pid=1");
342 ASSERT_TRUE(it.Next());
343 ASSERT_EQ(it.Get(0).long_value, 14);
344
345 it = Query(
346 "create view slices_1st_build as select slices.* from slices left "
347 "join thread_track on(slices.track_id == thread_track.id) left join "
348 "thread using(utid) left join process using(upid) where pid=2");
349 it.Next();
350 ASSERT_TRUE(it.Status().ok());
351
352 it = Query("select (max(ts) - min(ts)) / 1000000 from slices_1st_build");
353 ASSERT_TRUE(it.Next());
354 ASSERT_EQ(it.Get(0).long_value, 12612);
355
356 it = Query("select name from slices_1st_build order by ts desc limit 1");
357 ASSERT_TRUE(it.Next());
358 ASSERT_STREQ(it.Get(0).string_value,
359 "obj/src/trace_processor/unittests.trace_sorter_unittest.o");
360
361 it = Query("select sum(dur) / 1000000 from slices_1st_build");
362 ASSERT_TRUE(it.Next());
363 ASSERT_EQ(it.Get(0).long_value, 276174);
364 }
365
366 } // namespace
367 } // namespace trace_processor
368 } // namespace perfetto
369