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