1 /*
2 * Copyright (C) 2015 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 <cctype>
19 #include <functional>
20 #include <iterator>
21 #include <memory>
22 #include <mutex>
23 #include <regex>
24 #include <string>
25 #include <unordered_set>
26
27 #include <fcntl.h>
28 #include <stdio.h>
29 #include <libgen.h>
30 #include <sys/types.h>
31 #include <sys/stat.h>
32
33 #include <android-base/file.h>
34 #include <android-base/logging.h>
35 #include <android-base/macros.h>
36 #include <android-base/stringprintf.h>
37 #include <android-base/strings.h>
38 #include <android-base/thread_annotations.h>
39 #include <gtest/gtest.h>
40 #include <zlib.h>
41
42 #include "config.h"
43 #include "configreader.h"
44 #include "map_utils.h"
45 #include "perfprofdcore.h"
46 #include "perfprofd_cmdline.h"
47 #include "perfprofd_perf.h"
48 #include "perfprofd_threaded_handler.h"
49 #include "quipper_helper.h"
50 #include "symbolizer.h"
51
52 #include "perfprofd_record.pb.h"
53
54 using namespace android::perfprofd::quipper;
55
56 static_assert(android::base::kEnableDChecks, "Expected DCHECKs to be enabled");
57
58 //
59 // Set to argv[0] on startup
60 //
61 static std::string gExecutableRealpath;
62
63 namespace {
64
65 using android::base::LogId;
66 using android::base::LogSeverity;
67
68 class TestLogHelper {
69 public:
Install()70 void Install() {
71 using namespace std::placeholders;
72 android::base::SetLogger(
73 std::bind(&TestLogHelper::TestLogFunction, this, _1, _2, _3, _4, _5, _6));
74 }
75
JoinTestLog(const char * delimiter)76 std::string JoinTestLog(const char* delimiter) {
77 std::unique_lock<std::mutex> ul(lock_);
78 return android::base::Join(test_log_messages_, delimiter);
79 }
80 template <typename Predicate>
JoinTestLog(const char * delimiter,Predicate pred)81 std::string JoinTestLog(const char* delimiter, Predicate pred) {
82 std::unique_lock<std::mutex> ul(lock_);
83 std::vector<std::string> tmp;
84 std::copy_if(test_log_messages_.begin(),
85 test_log_messages_.end(),
86 std::back_inserter(tmp),
87 pred);
88 return android::base::Join(tmp, delimiter);
89 }
90
91 private:
TestLogFunction(LogId log_id,LogSeverity severity,const char * tag,const char * file,unsigned int line,const char * message)92 void TestLogFunction(LogId log_id,
93 LogSeverity severity,
94 const char* tag,
95 const char* file,
96 unsigned int line,
97 const char* message) {
98 std::unique_lock<std::mutex> ul(lock_);
99 constexpr char log_characters[] = "VDIWEFF";
100 char severity_char = log_characters[severity];
101 test_log_messages_.push_back(android::base::StringPrintf("%c: %s", severity_char, message));
102
103 if (severity >= LogSeverity::FATAL_WITHOUT_ABORT) {
104 android::base::StderrLogger(log_id, severity, tag, file, line, message);
105 }
106 }
107
108 private:
109 std::mutex lock_;
110
111 std::vector<std::string> test_log_messages_;
112 };
113
114 } // namespace
115
116 // Path to perf executable on device
117 #define PERFPATH "/system/bin/perf"
118
119 // Temporary config file that we will emit for the daemon to read
120 #define CONFIGFILE "perfprofd.conf"
121
bothWhiteSpace(char lhs,char rhs)122 static bool bothWhiteSpace(char lhs, char rhs)
123 {
124 return (std::isspace(lhs) && std::isspace(rhs));
125 }
126
127 #ifdef __ANDROID__
128
IsPerfSupported()129 static bool IsPerfSupported() {
130 auto check_perf_supported = []() {
131 #if defined(__i386__) || defined(__x86_64__)
132 // Cloud devices may suppress perf. Check for arch_perfmon.
133 std::string cpuinfo;
134 if (!android::base::ReadFileToString("/proc/cpuinfo", &cpuinfo)) {
135 // This is pretty unexpected. Return true to see if we can run tests anyways.
136 return true;
137 }
138 return cpuinfo.find("arch_perfmon") != std::string::npos;
139 #else
140 // Expect other architectures to have perf support.
141 return true;
142 #endif
143 };
144 static bool perf_supported = check_perf_supported();
145 return perf_supported;
146 }
147
148 #endif
149
150 //
151 // Squeeze out repeated whitespace from expected/actual logs.
152 //
squeezeWhite(const std::string & str,const char * tag,bool dump=false)153 static std::string squeezeWhite(const std::string &str,
154 const char *tag,
155 bool dump=false)
156 {
157 if (dump) { fprintf(stderr, "raw %s is %s\n", tag, str.c_str()); }
158 std::string result(str);
159 std::replace(result.begin(), result.end(), '\n', ' ');
160 auto new_end = std::unique(result.begin(), result.end(), bothWhiteSpace);
161 result.erase(new_end, result.end());
162 while (result.begin() != result.end() && std::isspace(*result.rbegin())) {
163 result.pop_back();
164 }
165 if (dump) { fprintf(stderr, "squeezed %s is %s\n", tag, result.c_str()); }
166 return result;
167 }
168
169 //
170 // Replace all occurrences of a string with another string.
171 //
replaceAll(const std::string & str,const std::string & from,const std::string & to)172 static std::string replaceAll(const std::string &str,
173 const std::string &from,
174 const std::string &to)
175 {
176 std::string ret = "";
177 size_t pos = 0;
178 while (pos < str.size()) {
179 size_t found = str.find(from, pos);
180 if (found == std::string::npos) {
181 ret += str.substr(pos);
182 break;
183 }
184 ret += str.substr(pos, found - pos) + to;
185 pos = found + from.size();
186 }
187 return ret;
188 }
189
190 //
191 // Replace occurrences of special variables in the string.
192 //
193 #ifdef __ANDROID__
expandVars(const std::string & str)194 static std::string expandVars(const std::string &str) {
195 #ifdef __LP64__
196 return replaceAll(str, "$NATIVE_TESTS", "/data/nativetest64");
197 #else
198 return replaceAll(str, "$NATIVE_TESTS", "/data/nativetest");
199 #endif
200 }
201 #endif
202
203 class PerfProfdTest : public testing::Test {
204 protected:
SetUp()205 virtual void SetUp() {
206 test_logger.Install();
207 create_dirs();
208 }
209
TearDown()210 virtual void TearDown() {
211 android::base::SetLogger(android::base::StderrLogger);
212
213 // TODO: proper management of test files. For now, use old system() code.
214 for (const auto dir : { &dest_dir, &conf_dir }) {
215 std::string cmd("rm -rf ");
216 cmd += *dir;
217 int ret = system(cmd.c_str());
218 CHECK_EQ(0, ret);
219 }
220 }
221
222 protected:
223 //
224 // Check to see if the log messages emitted by the daemon
225 // match the expected result. By default we use a partial
226 // match, e.g. if we see the expected excerpt anywhere in the
227 // result, it's a match (for exact match, set exact to true)
228 //
CompareLogMessages(const std::string & expected,bool exactMatch=false)229 ::testing::AssertionResult CompareLogMessages(const std::string& expected,
230 bool exactMatch = false) {
231 std::string sqexp = squeezeWhite(expected, "expected");
232
233 // Strip out JIT errors.
234 std::regex jit_regex("E: Failed to open ELF file: [^ ]*dalvik-jit-code-cache.*");
235 auto strip_jit = [&](const std::string& str) {
236 std::smatch jit_match;
237 return !std::regex_match(str, jit_match, jit_regex);
238 };
239 std::string sqact = squeezeWhite(test_logger.JoinTestLog(" ", strip_jit), "actual");
240
241 if (exactMatch) {
242 if (sqexp == sqact) {
243 return ::testing::AssertionSuccess() << sqexp << " is equal to " << sqact;
244 }
245 return ::testing::AssertionFailure() << "Expected:" << std::endl << sqexp << std::endl
246 << "Received:" << std::endl << sqact;
247 } else {
248 if (sqact.find(sqexp) == std::string::npos) {
249 return ::testing::AssertionFailure()
250 << "Expected to find:" << std::endl << sqexp << std::endl
251 << "in:" << std::endl << sqact;
252 }
253 return ::testing::AssertionSuccess() << sqexp << " was found in " << sqact;
254 }
255 }
256
257 // test_dir is the directory containing the test executable and
258 // any files associated with the test (will be created by the harness).
259 std::string test_dir;
260
261 // dest_dir is a temporary directory that we're using as the destination directory.
262 // It is backed by temp_dir1.
263 std::string dest_dir;
264
265 // conf_dir is a temporary directory that we're using as the configuration directory.
266 // It is backed by temp_dir2.
267 std::string conf_dir;
268
269 TestLogHelper test_logger;
270
271 private:
create_dirs()272 void create_dirs() {
273 temp_dir1.reset(new TemporaryDir());
274 temp_dir2.reset(new TemporaryDir());
275 dest_dir = temp_dir1->path;
276 conf_dir = temp_dir2->path;
277 test_dir = android::base::Dirname(gExecutableRealpath);
278 }
279
280 std::unique_ptr<TemporaryDir> temp_dir1;
281 std::unique_ptr<TemporaryDir> temp_dir2;
282 };
283
284 ///
285 /// Helper class to kick off a run of the perfprofd daemon with a specific
286 /// config file.
287 ///
288 class PerfProfdRunner {
289 public:
PerfProfdRunner(const std::string & config_dir)290 explicit PerfProfdRunner(const std::string& config_dir)
291 : config_dir_(config_dir)
292 {
293 config_path_ = config_dir + "/" CONFIGFILE;
294 }
295
~PerfProfdRunner()296 ~PerfProfdRunner()
297 {
298 remove_processed_file();
299 }
300
addToConfig(const std::string & line)301 void addToConfig(const std::string &line)
302 {
303 config_text_ += line;
304 config_text_ += "\n";
305 }
306
remove_semaphore_file()307 void remove_semaphore_file()
308 {
309 std::string semaphore(config_dir_);
310 semaphore += "/" SEMAPHORE_FILENAME;
311 unlink(semaphore.c_str());
312 }
313
create_semaphore_file()314 void create_semaphore_file()
315 {
316 std::string semaphore(config_dir_);
317 semaphore += "/" SEMAPHORE_FILENAME;
318 close(open(semaphore.c_str(), O_WRONLY|O_CREAT, 0600));
319 }
320
write_processed_file(int start_seq,int end_seq)321 void write_processed_file(int start_seq, int end_seq)
322 {
323 std::string processed = config_dir_ + "/" PROCESSED_FILENAME;
324 FILE *fp = fopen(processed.c_str(), "w");
325 for (int i = start_seq; i < end_seq; i++) {
326 fprintf(fp, "%d\n", i);
327 }
328 fclose(fp);
329 }
330
remove_processed_file()331 void remove_processed_file()
332 {
333 std::string processed = config_dir_ + "/" PROCESSED_FILENAME;
334 unlink(processed.c_str());
335 }
336
337 struct LoggingConfig : public Config {
SleepPerfProfdRunner::LoggingConfig338 void Sleep(size_t seconds) override {
339 // Log sleep calls but don't sleep.
340 LOG(INFO) << "sleep " << seconds << " seconds";
341 }
342
IsProfilingEnabledPerfProfdRunner::LoggingConfig343 bool IsProfilingEnabled() const override {
344 //
345 // Check for existence of semaphore file in config directory
346 //
347 if (access(config_directory.c_str(), F_OK) == -1) {
348 PLOG(WARNING) << "unable to open config directory " << config_directory;
349 return false;
350 }
351
352 // Check for existence of semaphore file
353 std::string semaphore_filepath = config_directory
354 + "/" + SEMAPHORE_FILENAME;
355 if (access(semaphore_filepath.c_str(), F_OK) == -1) {
356 return false;
357 }
358
359 return true;
360 }
361 };
362
invoke()363 int invoke()
364 {
365 static const char *argv[3] = { "perfprofd", "-c", "" };
366 argv[2] = config_path_.c_str();
367
368 writeConfigFile(config_path_, config_text_);
369
370 // execute daemon main
371 LoggingConfig config;
372 return perfprofd_main(3, (char **) argv, &config);
373 }
374
375 private:
376 std::string config_dir_;
377 std::string config_path_;
378 std::string config_text_;
379
writeConfigFile(const std::string & config_path,const std::string & config_text)380 void writeConfigFile(const std::string &config_path,
381 const std::string &config_text)
382 {
383 FILE *fp = fopen(config_path.c_str(), "w");
384 ASSERT_TRUE(fp != nullptr);
385 fprintf(fp, "%s\n", config_text.c_str());
386 fclose(fp);
387 }
388 };
389
390 //......................................................................
391
encoded_file_path(const std::string & dest_dir,int seq)392 static std::string encoded_file_path(const std::string& dest_dir,
393 int seq) {
394 return android::base::StringPrintf("%s/perf.data.encoded.%d",
395 dest_dir.c_str(), seq);
396 }
397
readEncodedProfile(const std::string & dest_dir,bool compressed,android::perfprofd::PerfprofdRecord & encodedProfile)398 static void readEncodedProfile(const std::string& dest_dir,
399 bool compressed,
400 android::perfprofd::PerfprofdRecord& encodedProfile)
401 {
402 struct stat statb;
403 int perf_data_stat_result = stat(encoded_file_path(dest_dir, 0).c_str(), &statb);
404 ASSERT_NE(-1, perf_data_stat_result);
405
406 // read
407 std::string encoded;
408 encoded.resize(statb.st_size);
409 FILE *ifp = fopen(encoded_file_path(dest_dir, 0).c_str(), "r");
410 ASSERT_NE(nullptr, ifp);
411 size_t items_read = fread((void*) encoded.data(), statb.st_size, 1, ifp);
412 ASSERT_EQ(1, items_read);
413 fclose(ifp);
414
415 // uncompress
416 if (compressed && !encoded.empty()) {
417 z_stream stream;
418 stream.zalloc = Z_NULL;
419 stream.zfree = Z_NULL;
420 stream.opaque = Z_NULL;
421
422 {
423 constexpr int kWindowBits = 15;
424 constexpr int kGzipEncoding = 16;
425 int init_result = inflateInit2(&stream, kWindowBits | kGzipEncoding);
426 if (init_result != Z_OK) {
427 LOG(ERROR) << "Could not initialize libz stream " << init_result;
428 return;
429 }
430 }
431
432 std::string buf;
433 buf.reserve(2 * encoded.size());
434 stream.avail_in = encoded.size();
435 stream.next_in = reinterpret_cast<Bytef*>(const_cast<char*>(encoded.data()));
436
437 int result;
438 do {
439 uint8_t chunk[1024];
440 stream.next_out = static_cast<Bytef*>(chunk);
441 stream.avail_out = arraysize(chunk);
442
443 result = inflate(&stream, 0);
444 const size_t amount = arraysize(chunk) - stream.avail_out;
445 if (amount > 0) {
446 if (buf.capacity() - buf.size() < amount) {
447 buf.reserve(buf.capacity() + 64u * 1024u);
448 CHECK_LE(amount, buf.capacity() - buf.size());
449 }
450 size_t index = buf.size();
451 buf.resize(buf.size() + amount);
452 memcpy(reinterpret_cast<uint8_t*>(const_cast<char*>(buf.data())) + index, chunk, amount);
453 }
454 } while (result == Z_OK);
455 inflateEnd(&stream);
456 if (result != Z_STREAM_END) {
457 LOG(ERROR) << "Finished with not-Z_STREAM_END " << result;
458 return;
459 }
460 encoded = buf;
461 }
462
463 // decode
464 encodedProfile.ParseFromString(encoded);
465 }
466
467 #define RAW_RESULT(x) #x
468
TEST_F(PerfProfdTest,TestUtil)469 TEST_F(PerfProfdTest, TestUtil)
470 {
471 EXPECT_EQ("", replaceAll("", "", ""));
472 EXPECT_EQ("zzbc", replaceAll("abc", "a", "zz"));
473 EXPECT_EQ("azzc", replaceAll("abc", "b", "zz"));
474 EXPECT_EQ("abzz", replaceAll("abc", "c", "zz"));
475 EXPECT_EQ("xxyyzz", replaceAll("abc", "abc", "xxyyzz"));
476 }
477
TEST_F(PerfProfdTest,MissingGMS)478 TEST_F(PerfProfdTest, MissingGMS)
479 {
480 //
481 // AWP requires cooperation between the daemon and the GMS core
482 // piece. If we're running on a device that has an old or damaged
483 // version of GMS core, then the config directory we're interested in
484 // may not be there. This test insures that the daemon does the
485 // right thing in this case.
486 //
487 PerfProfdRunner runner(conf_dir);
488 runner.addToConfig("only_debug_build=0");
489 runner.addToConfig("trace_config_read=0");
490 runner.addToConfig("config_directory=/does/not/exist");
491 runner.addToConfig("main_loop_iterations=1");
492 runner.addToConfig("use_fixed_seed=1");
493 runner.addToConfig("collection_interval=100");
494
495 // Kick off daemon
496 int daemon_main_return_code = runner.invoke();
497
498 // Check return code from daemon
499 EXPECT_EQ(0, daemon_main_return_code);
500
501 // Verify log contents
502 const std::string expected = RAW_RESULT(
503 I: sleep 90 seconds
504 W: unable to open config directory /does/not/exist: No such file or directory
505 I: profile collection skipped (missing config directory)
506 );
507
508 // check to make sure entire log matches
509 EXPECT_TRUE(CompareLogMessages(expected));
510 }
511
512
TEST_F(PerfProfdTest,MissingOptInSemaphoreFile)513 TEST_F(PerfProfdTest, MissingOptInSemaphoreFile)
514 {
515 //
516 // Android device owners must opt in to "collect and report usage
517 // data" in order for us to be able to collect profiles. The opt-in
518 // check is performed in the GMS core component; if the check
519 // passes, then it creates a semaphore file for the daemon to pick
520 // up on.
521 //
522 PerfProfdRunner runner(conf_dir);
523 runner.addToConfig("only_debug_build=0");
524 std::string cfparam("config_directory="); cfparam += conf_dir;
525 runner.addToConfig(cfparam);
526 std::string ddparam("destination_directory="); ddparam += dest_dir;
527 runner.addToConfig(ddparam);
528 runner.addToConfig("main_loop_iterations=1");
529 runner.addToConfig("use_fixed_seed=1");
530 runner.addToConfig("collection_interval=100");
531
532 runner.remove_semaphore_file();
533
534 // Kick off daemon
535 int daemon_main_return_code = runner.invoke();
536
537 // Check return code from daemon
538 EXPECT_EQ(0, daemon_main_return_code);
539
540 // Verify log contents
541 const std::string expected = RAW_RESULT(
542 I: profile collection skipped (missing config directory)
543 );
544 // check to make sure log excerpt matches
545 EXPECT_TRUE(CompareLogMessages(expected));
546 }
547
TEST_F(PerfProfdTest,MissingPerfExecutable)548 TEST_F(PerfProfdTest, MissingPerfExecutable)
549 {
550 //
551 // Perfprofd uses the 'simpleperf' tool to collect profiles
552 // (although this may conceivably change in the future). This test
553 // checks to make sure that if 'simpleperf' is not present we bail out
554 // from collecting profiles.
555 //
556 PerfProfdRunner runner(conf_dir);
557 runner.addToConfig("only_debug_build=0");
558 runner.addToConfig("trace_config_read=1");
559 std::string cfparam("config_directory="); cfparam += conf_dir;
560 runner.addToConfig(cfparam);
561 std::string ddparam("destination_directory="); ddparam += dest_dir;
562 runner.addToConfig(ddparam);
563 runner.addToConfig("main_loop_iterations=1");
564 runner.addToConfig("use_fixed_seed=1");
565 runner.addToConfig("collection_interval=100");
566 runner.addToConfig("perf_path=/does/not/exist");
567
568 // Create semaphore file
569 runner.create_semaphore_file();
570
571 // Kick off daemon
572 int daemon_main_return_code = runner.invoke();
573
574 // Check return code from daemon
575 EXPECT_EQ(0, daemon_main_return_code);
576
577 // expected log contents
578 const std::string expected = RAW_RESULT(
579 I: profile collection skipped (missing 'perf' executable)
580 );
581 // check to make sure log excerpt matches
582 EXPECT_TRUE(CompareLogMessages(expected));
583 }
584
TEST_F(PerfProfdTest,BadPerfRun)585 TEST_F(PerfProfdTest, BadPerfRun)
586 {
587 //
588 // Perf tools tend to be tightly coupled with a specific kernel
589 // version -- if things are out of sync perf could fail or
590 // crash. This test makes sure that we detect such a case and log
591 // the error.
592 //
593 PerfProfdRunner runner(conf_dir);
594 runner.addToConfig("only_debug_build=0");
595 std::string cfparam("config_directory="); cfparam += conf_dir;
596 runner.addToConfig(cfparam);
597 std::string ddparam("destination_directory="); ddparam += dest_dir;
598 runner.addToConfig(ddparam);
599 runner.addToConfig("main_loop_iterations=1");
600 runner.addToConfig("use_fixed_seed=1");
601 runner.addToConfig("collection_interval=100");
602 #ifdef __ANDROID__
603 runner.addToConfig("perf_path=/system/bin/false");
604 #else
605 runner.addToConfig("perf_path=/bin/false");
606 #endif
607
608 // Create semaphore file
609 runner.create_semaphore_file();
610
611 // Kick off daemon
612 int daemon_main_return_code = runner.invoke();
613
614 // Check return code from daemon
615 EXPECT_EQ(0, daemon_main_return_code);
616
617 // Verify log contents. Because of perferr logging containing pids and test paths,
618 // it is easier to have three expected parts.
619 const std::string expected1 = "W: perf bad exit status 1";
620 const std::string expected2 = "bin/false record";
621 const std::string expected3 = "W: profile collection failed";
622
623 // check to make sure log excerpt matches
624 EXPECT_TRUE(CompareLogMessages(expected1));
625 EXPECT_TRUE(CompareLogMessages(expected2));
626 EXPECT_TRUE(CompareLogMessages(expected3));
627 }
628
TEST_F(PerfProfdTest,ConfigFileParsing)629 TEST_F(PerfProfdTest, ConfigFileParsing)
630 {
631 //
632 // Gracefully handly malformed items in the config file
633 //
634 PerfProfdRunner runner(conf_dir);
635 runner.addToConfig("only_debug_build=0");
636 runner.addToConfig("main_loop_iterations=1");
637 runner.addToConfig("collection_interval=100");
638 runner.addToConfig("use_fixed_seed=1");
639 runner.addToConfig("destination_directory=/does/not/exist");
640
641 // assorted bad syntax
642 runner.addToConfig("collection_interval=-1");
643 runner.addToConfig("collection_interval=18446744073709551615");
644 runner.addToConfig("nonexistent_key=something");
645 runner.addToConfig("no_equals_stmt");
646
647 // Kick off daemon
648 int daemon_main_return_code = runner.invoke();
649
650 // Check return code from daemon
651 EXPECT_EQ(0, daemon_main_return_code);
652
653 // Verify log contents
654 const std::string expected = RAW_RESULT(
655 W: line 6: value -1 cannot be parsed
656 W: line 7: specified value 18446744073709551615 for 'collection_interval' outside permitted range [0 4294967295]
657 W: line 8: unknown option 'nonexistent_key'
658 W: line 9: line malformed (no '=' found)
659 );
660
661 // check to make sure log excerpt matches
662 EXPECT_TRUE(CompareLogMessages(expected));
663 }
664
TEST_F(PerfProfdTest,ConfigFileParsing_Events)665 TEST_F(PerfProfdTest, ConfigFileParsing_Events) {
666 auto check_event_config = [](const Config& config,
667 size_t index,
668 const std::vector<std::string>& names,
669 bool group,
670 uint32_t period) {
671 if (config.event_config.size() <= index) {
672 return ::testing::AssertionFailure() << "Not enough entries " << config.event_config.size()
673 << " " << index;
674 }
675 const auto& elem = config.event_config[index];
676
677 if (elem.group != group) {
678 return ::testing::AssertionFailure() << "Type wrong " << elem.group << " " << group;
679 }
680
681 if (elem.sampling_period != period) {
682 return ::testing::AssertionFailure() << "Period wrong " << elem.sampling_period << " "
683 << period;
684 }
685
686 auto strvec = [](const std::vector<std::string>& v) {
687 return "[" + android::base::Join(v, ',') + "]";
688 };
689 if (elem.events.size() != names.size()) {
690 return ::testing::AssertionFailure() << "Names wrong " << strvec(elem.events) << " "
691 << strvec(names);
692 }
693 for (size_t i = 0; i != elem.events.size(); ++i) {
694 if (elem.events[i] != names[i]) {
695 return ::testing::AssertionFailure() << "Names wrong at " << i << ": "
696 << strvec(elem.events) << " "
697 << strvec(names);
698 }
699 }
700 return ::testing::AssertionSuccess();
701 };
702
703 {
704 std::string data = "-e_hello,world=1\n"
705 "-g_foo,bar=2\n"
706 "-e_abc,xyz=3\n"
707 "-g_ftrace:test,ftrace:test2=4";
708
709 ConfigReader reader;
710 std::string error_msg;
711 ASSERT_TRUE(reader.Read(data, true, &error_msg)) << error_msg;
712
713 PerfProfdRunner::LoggingConfig config;
714 reader.FillConfig(&config);
715
716 EXPECT_TRUE(check_event_config(config, 0, { "hello", "world" }, false, 1));
717 EXPECT_TRUE(check_event_config(config, 1, { "foo", "bar" }, true, 2));
718 EXPECT_TRUE(check_event_config(config, 2, { "abc", "xyz" }, false, 3));
719 EXPECT_TRUE(check_event_config(config, 3, { "ftrace:test", "ftrace:test2" }, true, 4));
720 }
721
722 {
723 std::string data = "-e_hello,world=dummy";
724
725 ConfigReader reader;
726 std::string error_msg;
727 EXPECT_FALSE(reader.Read(data, true, &error_msg));
728 }
729
730 {
731 std::string data = "-g_hello,world=dummy";
732
733 ConfigReader reader;
734 std::string error_msg;
735 EXPECT_FALSE(reader.Read(data, true, &error_msg));
736 }
737 }
738
739
TEST_F(PerfProfdTest,ConfigDump)740 TEST_F(PerfProfdTest, ConfigDump) {
741 constexpr const char* kConfigElems[] = {
742 "collection_interval=14400",
743 "use_fixed_seed=1",
744 "main_loop_iterations=2",
745 "destination_directory=/does/not/exist",
746 "config_directory=a",
747 "perf_path=/system/xbin/simpleperf2",
748 "sampling_period=3",
749 "sampling_frequency=4",
750 "sample_duration=5",
751 "only_debug_build=1",
752 "hardwire_cpus=1",
753 "hardwire_cpus_max_duration=6",
754 "max_unprocessed_profiles=7",
755 "stack_profile=1",
756 "trace_config_read=1",
757 "collect_cpu_utilization=1",
758 "collect_charging_state=1",
759 "collect_booting=1",
760 "collect_camera_active=1",
761 "process=8",
762 "use_elf_symbolizer=1",
763 "symbolize_everything=1",
764 "compress=1",
765 "dropbox=1",
766 "fail_on_unsupported_events=1",
767 "-e_hello,world=1",
768 "-g_foo,bar=2",
769 "-e_abc,xyz=3",
770 "-g_ftrace:test,ftrace:test2=4",
771 };
772
773 std::string input;
774 for (const char* elem : kConfigElems) {
775 input.append(elem);
776 input.append("\n");
777 }
778
779 ConfigReader reader;
780 std::string error_msg;
781 ASSERT_TRUE(reader.Read(input, false, &error_msg)) << error_msg;
782
783 PerfProfdRunner::LoggingConfig config;
784 reader.FillConfig(&config);
785
786 std::string output = ConfigReader::ConfigToString(config);
787 for (const char* elem : kConfigElems) {
788 EXPECT_TRUE(output.find(elem) != std::string::npos) << elem << " not in " << output;
789 }
790 }
791
TEST_F(PerfProfdTest,ProfileCollectionAnnotations)792 TEST_F(PerfProfdTest, ProfileCollectionAnnotations)
793 {
794 unsigned util1 = collect_cpu_utilization();
795 EXPECT_LE(util1, 100);
796 EXPECT_GE(util1, 0);
797
798 // NB: expectation is that when we run this test, the device will be
799 // completed booted, will be on charger, and will not have the camera
800 // active.
801 EXPECT_FALSE(get_booting());
802 #ifdef __ANDROID__
803 EXPECT_TRUE(get_charging());
804 #endif
805 EXPECT_FALSE(get_camera_active());
806 }
807
808 namespace {
809
810 template <typename Iterator>
CountEvents(const quipper::PerfDataProto & proto)811 size_t CountEvents(const quipper::PerfDataProto& proto) {
812 size_t count = 0;
813 for (Iterator it(proto); it != it.end(); ++it) {
814 count++;
815 }
816 return count;
817 }
818
CountCommEvents(const quipper::PerfDataProto & proto)819 size_t CountCommEvents(const quipper::PerfDataProto& proto) {
820 return CountEvents<CommEventIterator>(proto);
821 }
CountMmapEvents(const quipper::PerfDataProto & proto)822 size_t CountMmapEvents(const quipper::PerfDataProto& proto) {
823 return CountEvents<MmapEventIterator>(proto);
824 }
CountSampleEvents(const quipper::PerfDataProto & proto)825 size_t CountSampleEvents(const quipper::PerfDataProto& proto) {
826 return CountEvents<SampleEventIterator>(proto);
827 }
CountForkEvents(const quipper::PerfDataProto & proto)828 size_t CountForkEvents(const quipper::PerfDataProto& proto) {
829 return CountEvents<ForkEventIterator>(proto);
830 }
CountExitEvents(const quipper::PerfDataProto & proto)831 size_t CountExitEvents(const quipper::PerfDataProto& proto) {
832 return CountEvents<ExitEventIterator>(proto);
833 }
834
CreateStats(const quipper::PerfDataProto & proto)835 std::string CreateStats(const quipper::PerfDataProto& proto) {
836 std::ostringstream oss;
837 oss << "Mmap events: " << CountMmapEvents(proto) << std::endl;
838 oss << "Sample events: " << CountSampleEvents(proto) << std::endl;
839 oss << "Comm events: " << CountCommEvents(proto) << std::endl;
840 oss << "Fork events: " << CountForkEvents(proto) << std::endl;
841 oss << "Exit events: " << CountExitEvents(proto) << std::endl;
842 return oss.str();
843 }
844
FormatSampleEvent(const quipper::PerfDataProto_SampleEvent & sample)845 std::string FormatSampleEvent(const quipper::PerfDataProto_SampleEvent& sample) {
846 std::ostringstream oss;
847 if (sample.has_pid()) {
848 oss << "pid=" << sample.pid();
849 }
850 if (sample.has_tid()) {
851 oss << " tid=" << sample.tid();
852 }
853 if (sample.has_ip()) {
854 oss << " ip=" << sample.ip();
855 }
856 if (sample.has_addr()) {
857 oss << " addr=" << sample.addr();
858 }
859 if (sample.callchain_size() > 0) {
860 oss << " callchain=";
861 for (uint64_t cc : sample.callchain()) {
862 oss << "->" << cc;
863 }
864 }
865 return oss.str();
866 }
867
868 }
869
870 struct BasicRunWithCannedPerf : PerfProfdTest {
VerifyBasicCannedProfileBasicRunWithCannedPerf871 void VerifyBasicCannedProfile(const android::perfprofd::PerfprofdRecord& encodedProfile) {
872 const quipper::PerfDataProto& perf_data = encodedProfile;
873
874 // Expect 21108 events.
875 EXPECT_EQ(21108, perf_data.events_size()) << CreateStats(perf_data);
876
877 EXPECT_EQ(48, CountMmapEvents(perf_data)) << CreateStats(perf_data);
878 EXPECT_EQ(19986, CountSampleEvents(perf_data)) << CreateStats(perf_data);
879 EXPECT_EQ(1033, CountCommEvents(perf_data)) << CreateStats(perf_data);
880 EXPECT_EQ(15, CountForkEvents(perf_data)) << CreateStats(perf_data);
881 EXPECT_EQ(26, CountExitEvents(perf_data)) << CreateStats(perf_data);
882
883 if (HasNonfatalFailure()) {
884 FAIL();
885 }
886
887 {
888 MmapEventIterator mmap(perf_data);
889 constexpr std::pair<const char*, uint64_t> kMmapEvents[] = {
890 std::make_pair("[kernel.kallsyms]_text", 0),
891 std::make_pair("/system/lib/libc.so", 3067412480u),
892 std::make_pair("/system/vendor/lib/libdsutils.so", 3069911040u),
893 std::make_pair("/system/lib/libc.so", 3067191296u),
894 std::make_pair("/system/lib/libc++.so", 3069210624u),
895 std::make_pair("/data/dalvik-cache/arm/system@framework@boot.oat", 1900048384u),
896 std::make_pair("/system/lib/libjavacore.so", 2957135872u),
897 std::make_pair("/system/vendor/lib/libqmi_encdec.so", 3006644224u),
898 std::make_pair("/data/dalvik-cache/arm/system@framework@wifi-service.jar@classes.dex",
899 3010351104u),
900 std::make_pair("/system/lib/libart.so", 3024150528u),
901 std::make_pair("/system/lib/libz.so", 3056410624u),
902 std::make_pair("/system/lib/libicui18n.so", 3057610752u),
903 };
904 for (auto& pair : kMmapEvents) {
905 EXPECT_STREQ(pair.first, mmap->mmap_event().filename().c_str());
906 EXPECT_EQ(pair.second, mmap->mmap_event().start()) << pair.first;
907 ++mmap;
908 }
909 }
910
911 {
912 CommEventIterator comm(perf_data);
913 constexpr const char* kCommEvents[] = {
914 "init", "kthreadd", "ksoftirqd/0", "kworker/u:0H", "migration/0", "khelper",
915 "netns", "modem_notifier", "smd_channel_clo", "smsm_cb_wq", "rpm-smd", "kworker/u:1H",
916 };
917 for (auto str : kCommEvents) {
918 EXPECT_STREQ(str, comm->comm_event().comm().c_str());
919 ++comm;
920 }
921 }
922
923 {
924 SampleEventIterator samples(perf_data);
925 constexpr const char* kSampleEvents[] = {
926 "pid=0 tid=0 ip=3222720196",
927 "pid=0 tid=0 ip=3222910876",
928 "pid=0 tid=0 ip=3222910876",
929 "pid=0 tid=0 ip=3222910876",
930 "pid=0 tid=0 ip=3222910876",
931 "pid=0 tid=0 ip=3222910876",
932 "pid=0 tid=0 ip=3222910876",
933 "pid=3 tid=3 ip=3231975108",
934 "pid=5926 tid=5926 ip=3231964952",
935 "pid=5926 tid=5926 ip=3225342428",
936 "pid=5926 tid=5926 ip=3223841448",
937 "pid=5926 tid=5926 ip=3069807920",
938 };
939 for (auto str : kSampleEvents) {
940 EXPECT_STREQ(str, FormatSampleEvent(samples->sample_event()).c_str());
941 ++samples;
942 }
943
944 // Skip some samples.
945 for (size_t i = 0; i != 5000; ++i) {
946 ++samples;
947 }
948 constexpr const char* kSampleEvents2[] = {
949 "pid=5938 tid=5938 ip=3069630992",
950 "pid=5938 tid=5938 ip=3069626616",
951 "pid=5938 tid=5938 ip=3069626636",
952 "pid=5938 tid=5938 ip=3069637212",
953 "pid=5938 tid=5938 ip=3069637208",
954 "pid=5938 tid=5938 ip=3069637252",
955 "pid=5938 tid=5938 ip=3069346040",
956 "pid=5938 tid=5938 ip=3069637128",
957 "pid=5938 tid=5938 ip=3069626616",
958 };
959 for (auto str : kSampleEvents2) {
960 EXPECT_STREQ(str, FormatSampleEvent(samples->sample_event()).c_str());
961 ++samples;
962 }
963
964 // Skip some samples.
965 for (size_t i = 0; i != 5000; ++i) {
966 ++samples;
967 }
968 constexpr const char* kSampleEvents3[] = {
969 "pid=5938 tid=5938 ip=3069912036",
970 "pid=5938 tid=5938 ip=3069637260",
971 "pid=5938 tid=5938 ip=3069631024",
972 "pid=5938 tid=5938 ip=3069346064",
973 "pid=5938 tid=5938 ip=3069637356",
974 "pid=5938 tid=5938 ip=3069637144",
975 "pid=5938 tid=5938 ip=3069912036",
976 "pid=5938 tid=5938 ip=3069912036",
977 "pid=5938 tid=5938 ip=3069631244",
978 };
979 for (auto str : kSampleEvents3) {
980 EXPECT_STREQ(str, FormatSampleEvent(samples->sample_event()).c_str());
981 ++samples;
982 }
983 }
984 }
985 };
986
TEST_F(BasicRunWithCannedPerf,Basic)987 TEST_F(BasicRunWithCannedPerf, Basic)
988 {
989 //
990 // Verify the portion of the daemon that reads and encodes
991 // perf.data files. Here we run the encoder on a canned perf.data
992 // file and verify that the resulting protobuf contains what
993 // we think it should contain.
994 //
995 std::string input_perf_data(test_dir);
996 input_perf_data += "/canned.perf.data";
997
998 // Set up config to avoid these annotations (they are tested elsewhere)
999 ConfigReader config_reader;
1000 config_reader.overrideUnsignedEntry("collect_cpu_utilization", 0);
1001 config_reader.overrideUnsignedEntry("collect_charging_state", 0);
1002 config_reader.overrideUnsignedEntry("collect_camera_active", 0);
1003
1004 // Disable compression.
1005 config_reader.overrideUnsignedEntry("compress", 0);
1006
1007 PerfProfdRunner::LoggingConfig config;
1008 config_reader.FillConfig(&config);
1009
1010 // Kick off encoder and check return code
1011 PROFILE_RESULT result =
1012 encode_to_proto(input_perf_data, encoded_file_path(dest_dir, 0).c_str(), config, 0, nullptr);
1013 ASSERT_EQ(OK_PROFILE_COLLECTION, result) << test_logger.JoinTestLog(" ");
1014
1015 // Read and decode the resulting perf.data.encoded file
1016 android::perfprofd::PerfprofdRecord encodedProfile;
1017 readEncodedProfile(dest_dir, false, encodedProfile);
1018
1019 VerifyBasicCannedProfile(encodedProfile);
1020 }
1021
TEST_F(BasicRunWithCannedPerf,Compressed)1022 TEST_F(BasicRunWithCannedPerf, Compressed)
1023 {
1024 //
1025 // Verify the portion of the daemon that reads and encodes
1026 // perf.data files. Here we run the encoder on a canned perf.data
1027 // file and verify that the resulting protobuf contains what
1028 // we think it should contain.
1029 //
1030 std::string input_perf_data(test_dir);
1031 input_perf_data += "/canned.perf.data";
1032
1033 // Set up config to avoid these annotations (they are tested elsewhere)
1034 ConfigReader config_reader;
1035 config_reader.overrideUnsignedEntry("collect_cpu_utilization", 0);
1036 config_reader.overrideUnsignedEntry("collect_charging_state", 0);
1037 config_reader.overrideUnsignedEntry("collect_camera_active", 0);
1038
1039 // Enable compression.
1040 config_reader.overrideUnsignedEntry("compress", 1);
1041
1042 PerfProfdRunner::LoggingConfig config;
1043 config_reader.FillConfig(&config);
1044
1045 // Kick off encoder and check return code
1046 PROFILE_RESULT result =
1047 encode_to_proto(input_perf_data, encoded_file_path(dest_dir, 0).c_str(), config, 0, nullptr);
1048 ASSERT_EQ(OK_PROFILE_COLLECTION, result) << test_logger.JoinTestLog(" ");
1049
1050 // Read and decode the resulting perf.data.encoded file
1051 android::perfprofd::PerfprofdRecord encodedProfile;
1052 readEncodedProfile(dest_dir, true, encodedProfile);
1053
1054 VerifyBasicCannedProfile(encodedProfile);
1055 }
1056
1057 class BasicRunWithCannedPerfWithSymbolizer : public BasicRunWithCannedPerf {
1058 protected:
Run(bool symbolize_everything,size_t expected_count)1059 std::vector<::testing::AssertionResult> Run(bool symbolize_everything, size_t expected_count) {
1060 //
1061 // Verify the portion of the daemon that reads and encodes
1062 // perf.data files. Here we run the encoder on a canned perf.data
1063 // file and verify that the resulting protobuf contains what
1064 // we think it should contain.
1065 //
1066 std::string input_perf_data(test_dir);
1067 input_perf_data += "/canned.perf.data";
1068
1069 // Set up config to avoid these annotations (they are tested elsewhere)
1070 ConfigReader config_reader;
1071 config_reader.overrideUnsignedEntry("collect_cpu_utilization", 0);
1072 config_reader.overrideUnsignedEntry("collect_charging_state", 0);
1073 config_reader.overrideUnsignedEntry("collect_camera_active", 0);
1074
1075 // Disable compression.
1076 config_reader.overrideUnsignedEntry("compress", 0);
1077
1078 if (symbolize_everything) {
1079 config_reader.overrideUnsignedEntry("symbolize_everything", 1);
1080 }
1081
1082 PerfProfdRunner::LoggingConfig config;
1083 config_reader.FillConfig(&config);
1084
1085 // Kick off encoder and check return code
1086 struct TestSymbolizer : public perfprofd::Symbolizer {
1087 std::string Decode(const std::string& dso, uint64_t address) override {
1088 return dso + "@" + std::to_string(address);
1089 }
1090 bool GetMinExecutableVAddr(const std::string& dso, uint64_t* addr) override {
1091 *addr = 4096;
1092 return true;
1093 }
1094 };
1095 TestSymbolizer test_symbolizer;
1096 PROFILE_RESULT result =
1097 encode_to_proto(input_perf_data,
1098 encoded_file_path(dest_dir, 0).c_str(),
1099 config,
1100 0,
1101 &test_symbolizer);
1102 if (result != OK_PROFILE_COLLECTION) {
1103 return { ::testing::AssertionFailure() << "Profile collection failed: " << result };
1104 }
1105
1106 std::vector<::testing::AssertionResult> ret;
1107
1108 // Read and decode the resulting perf.data.encoded file
1109 android::perfprofd::PerfprofdRecord encodedProfile;
1110 readEncodedProfile(dest_dir, false, encodedProfile);
1111
1112 VerifyBasicCannedProfile(encodedProfile);
1113
1114 auto find_symbol = [&](const std::string& filename) -> const quipper::SymbolInfo* {
1115 const size_t size = encodedProfile.ExtensionSize(quipper::symbol_info);
1116 for (size_t i = 0; i != size; ++i) {
1117 auto& symbol_info = encodedProfile.GetExtension(quipper::symbol_info, i);
1118 if (symbol_info.filename() == filename) {
1119 return &symbol_info;
1120 }
1121 }
1122 return nullptr;
1123 };
1124 auto all_filenames = [&]() {
1125 std::ostringstream oss;
1126 const size_t size = encodedProfile.ExtensionSize(quipper::symbol_info);
1127 for (size_t i = 0; i != size; ++i) {
1128 auto& symbol_info = encodedProfile.GetExtension(quipper::symbol_info, i);
1129 oss << " " << symbol_info.filename();
1130 }
1131 return oss.str();
1132 };
1133
1134 auto check_dsos = [&](const char* const* dsos, const size_t len) {
1135 bool failed = false;
1136 for (size_t i = 0; i != len; ++i) {
1137 if (find_symbol(dsos[i]) == nullptr) {
1138 failed = true;
1139 ret.push_back(::testing::AssertionFailure() << "Did not find " << dsos[i]);
1140 }
1141 }
1142 return failed;
1143 };
1144
1145 bool failed = false;
1146
1147 constexpr const char* kDSOs[] = {
1148 "/data/app/com.google.android.apps.plus-1/lib/arm/libcronet.so",
1149 "/data/dalvik-cache/arm/system@framework@wifi-service.jar@classes.dex",
1150 "/data/dalvik-cache/arm/data@app@com.google.android.gms-2@base.apk@classes.dex",
1151 "/data/dalvik-cache/arm/system@framework@boot.oat",
1152 };
1153 failed |= check_dsos(kDSOs, arraysize(kDSOs));
1154
1155 if (symbolize_everything) {
1156 constexpr const char* kDSOsWithBuildIDs[] = {
1157 "/system/lib/libz.so", "/system/lib/libutils.so",
1158 };
1159 failed |= check_dsos(kDSOsWithBuildIDs, arraysize(kDSOsWithBuildIDs));
1160 }
1161
1162 if (failed) {
1163 ret.push_back(::testing::AssertionFailure() << "Found: " << all_filenames());
1164 }
1165
1166 if (encodedProfile.ExtensionSize(quipper::symbol_info) != expected_count) {
1167 ret.push_back(
1168 ::testing::AssertionFailure() << "Expected " << expected_count
1169 << " symbolized libraries, found "
1170 << encodedProfile.ExtensionSize(quipper::symbol_info));
1171 }
1172
1173 return ret;
1174 }
1175 };
1176
TEST_F(BasicRunWithCannedPerfWithSymbolizer,Default)1177 TEST_F(BasicRunWithCannedPerfWithSymbolizer, Default) {
1178 auto result = Run(false, 5);
1179 for (const auto& result_component : result) {
1180 EXPECT_TRUE(result_component);
1181 }
1182 }
1183
TEST_F(BasicRunWithCannedPerfWithSymbolizer,Everything)1184 TEST_F(BasicRunWithCannedPerfWithSymbolizer, Everything) {
1185 auto result = Run(true, 26);
1186 for (const auto& result_component : result) {
1187 EXPECT_TRUE(result_component);
1188 }
1189 }
1190
TEST_F(PerfProfdTest,CallchainRunWithCannedPerf)1191 TEST_F(PerfProfdTest, CallchainRunWithCannedPerf)
1192 {
1193 // This test makes sure that the perf.data converter
1194 // can handle call chains.
1195 //
1196 std::string input_perf_data(test_dir);
1197 input_perf_data += "/callchain.canned.perf.data";
1198
1199 // Set up config to avoid these annotations (they are tested elsewhere)
1200 ConfigReader config_reader;
1201 config_reader.overrideUnsignedEntry("collect_cpu_utilization", 0);
1202 config_reader.overrideUnsignedEntry("collect_charging_state", 0);
1203 config_reader.overrideUnsignedEntry("collect_camera_active", 0);
1204
1205 // Disable compression.
1206 config_reader.overrideUnsignedEntry("compress", 0);
1207
1208 PerfProfdRunner::LoggingConfig config;
1209 config_reader.FillConfig(&config);
1210
1211 // Kick off encoder and check return code
1212 PROFILE_RESULT result =
1213 encode_to_proto(input_perf_data, encoded_file_path(dest_dir, 0).c_str(), config, 0, nullptr);
1214 ASSERT_EQ(OK_PROFILE_COLLECTION, result);
1215
1216 // Read and decode the resulting perf.data.encoded file
1217 android::perfprofd::PerfprofdRecord encodedProfile;
1218 readEncodedProfile(dest_dir, false, encodedProfile);
1219
1220 const quipper::PerfDataProto& perf_data = encodedProfile;
1221
1222 // Expect 21108 events.
1223 EXPECT_EQ(2224, perf_data.events_size()) << CreateStats(perf_data);
1224
1225 {
1226 SampleEventIterator samples(perf_data);
1227 constexpr const char* kSampleEvents[] = {
1228 "0: pid=6225 tid=6225 ip=18446743798834668032 callchain=->18446744073709551488->"
1229 "18446743798834668032->18446743798834782596->18446743798834784624->"
1230 "18446743798835055136->18446743798834788016->18446743798834789192->"
1231 "18446743798834789512->18446743798834790216->18446743798833756776",
1232 "1: pid=6225 tid=6225 ip=18446743798835685700 callchain=->18446744073709551488->"
1233 "18446743798835685700->18446743798835688704->18446743798835650964->"
1234 "18446743798834612104->18446743798834612276->18446743798835055528->"
1235 "18446743798834788016->18446743798834789192->18446743798834789512->"
1236 "18446743798834790216->18446743798833756776",
1237 "2: pid=6225 tid=6225 ip=18446743798835055804 callchain=->18446744073709551488->"
1238 "18446743798835055804->18446743798834788016->18446743798834789192->"
1239 "18446743798834789512->18446743798834790216->18446743798833756776",
1240 "3: pid=6225 tid=6225 ip=18446743798835991212 callchain=->18446744073709551488->"
1241 "18446743798835991212->18446743798834491060->18446743798834675572->"
1242 "18446743798834676516->18446743798834612172->18446743798834612276->"
1243 "18446743798835056664->18446743798834788016->18446743798834789192->"
1244 "18446743798834789512->18446743798834790216->18446743798833756776",
1245 "4: pid=6225 tid=6225 ip=18446743798844881108 callchain=->18446744073709551488->"
1246 "18446743798844881108->18446743798834836140->18446743798834846384->"
1247 "18446743798834491100->18446743798834675572->18446743798834676516->"
1248 "18446743798834612172->18446743798834612276->18446743798835056784->"
1249 "18446743798834788016->18446743798834789192->18446743798834789512->"
1250 "18446743798834790216->18446743798833756776",
1251 };
1252 size_t cmp_index = 0;
1253 for (size_t index = 0; samples != samples.end(); ++samples, ++index) {
1254 if (samples->sample_event().callchain_size() > 0) {
1255 std::ostringstream oss;
1256 oss << index << ": " << FormatSampleEvent(samples->sample_event());
1257 EXPECT_STREQ(kSampleEvents[cmp_index], oss.str().c_str());
1258 cmp_index++;
1259 if (cmp_index == arraysize(kSampleEvents)) {
1260 break;
1261 }
1262 }
1263 }
1264 }
1265 }
1266
1267 #ifdef __ANDROID__
1268
TEST_F(PerfProfdTest,GetSupportedPerfCounters)1269 TEST_F(PerfProfdTest, GetSupportedPerfCounters)
1270 {
1271 if (!IsPerfSupported()) {
1272 std::cerr << "Test not supported!" << std::endl;
1273 return;
1274 }
1275 // Check basic perf counters.
1276 {
1277 struct DummyConfig : public Config {
1278 void Sleep(size_t seconds) override {}
1279 bool IsProfilingEnabled() const override { return false; }
1280 };
1281 DummyConfig config;
1282 ASSERT_TRUE(android::perfprofd::FindSupportedPerfCounters(config.perf_path));
1283 }
1284 const std::unordered_set<std::string>& counters = android::perfprofd::GetSupportedPerfCounters();
1285 EXPECT_TRUE(std::find(counters.begin(), counters.end(), std::string("cpu-cycles"))
1286 != counters.end()) << android::base::Join(counters, ',');
1287 EXPECT_TRUE(std::find(counters.begin(), counters.end(), std::string("page-faults"))
1288 != counters.end()) << android::base::Join(counters, ',');
1289 }
1290
TEST_F(PerfProfdTest,BasicRunWithLivePerf)1291 TEST_F(PerfProfdTest, BasicRunWithLivePerf)
1292 {
1293 if (!IsPerfSupported()) {
1294 std::cerr << "Test not supported!" << std::endl;
1295 return;
1296 }
1297 //
1298 // Basic test to exercise the main loop of the daemon. It includes
1299 // a live 'perf' run
1300 //
1301 PerfProfdRunner runner(conf_dir);
1302 runner.addToConfig("only_debug_build=0");
1303 std::string ddparam("destination_directory="); ddparam += dest_dir;
1304 runner.addToConfig(ddparam);
1305 std::string cfparam("config_directory="); cfparam += conf_dir;
1306 runner.addToConfig(cfparam);
1307 runner.addToConfig("main_loop_iterations=1");
1308 runner.addToConfig("use_fixed_seed=12345678");
1309 runner.addToConfig("max_unprocessed_profiles=100");
1310 runner.addToConfig("collection_interval=9999");
1311 runner.addToConfig("sample_duration=2");
1312 // Avoid the symbolizer for spurious messages.
1313 runner.addToConfig("use_elf_symbolizer=0");
1314
1315 // Disable compression.
1316 runner.addToConfig("compress=0");
1317
1318 // Create semaphore file
1319 runner.create_semaphore_file();
1320
1321 // Kick off daemon
1322 int daemon_main_return_code = runner.invoke();
1323
1324 // Check return code from daemon
1325 ASSERT_EQ(0, daemon_main_return_code);
1326
1327 // Read and decode the resulting perf.data.encoded file
1328 android::perfprofd::PerfprofdRecord encodedProfile;
1329 readEncodedProfile(dest_dir, false, encodedProfile);
1330
1331 // Examine what we get back. Since it's a live profile, we can't
1332 // really do much in terms of verifying the contents.
1333 EXPECT_LT(0, encodedProfile.events_size());
1334
1335 // Verify log contents
1336 const std::string expected = std::string(
1337 "I: starting Android Wide Profiling daemon ") +
1338 "I: config file path set to " + conf_dir + "/perfprofd.conf " +
1339 RAW_RESULT(
1340 I: random seed set to 12345678
1341 I: sleep 674 seconds
1342 I: initiating profile collection
1343 I: sleep 2 seconds
1344 I: profile collection complete
1345 I: sleep 9325 seconds
1346 I: finishing Android Wide Profiling daemon
1347 );
1348 // check to make sure log excerpt matches
1349 EXPECT_TRUE(CompareLogMessages(expandVars(expected), true));
1350 }
1351
1352 class PerfProfdLiveEventsTest : public PerfProfdTest {
1353 protected:
SetupAndInvoke(const std::string & event_config,const std::vector<std::string> & extra_config,bool expect_success,std::string expected_log,bool log_match_exact)1354 ::testing::AssertionResult SetupAndInvoke(
1355 const std::string& event_config,
1356 const std::vector<std::string>& extra_config,
1357 bool expect_success,
1358 std::string expected_log,
1359 bool log_match_exact) {
1360 //
1361 // Basic test to check that the event set functionality works.
1362 //
1363 // Note: this is brittle, as we do not really know which events the hardware
1364 // supports. Use "cpu-cycles" and "page-faults" as something likely.
1365 //
1366 PerfProfdRunner runner(conf_dir);
1367 runner.addToConfig("only_debug_build=0");
1368 std::string ddparam("destination_directory="); ddparam += dest_dir;
1369 runner.addToConfig(ddparam);
1370 std::string cfparam("config_directory="); cfparam += conf_dir;
1371 runner.addToConfig(cfparam);
1372 runner.addToConfig("main_loop_iterations=1");
1373 runner.addToConfig("use_fixed_seed=12345678");
1374 runner.addToConfig("max_unprocessed_profiles=100");
1375 runner.addToConfig("collection_interval=9999");
1376 runner.addToConfig("sample_duration=2");
1377 // Avoid the symbolizer for spurious messages.
1378 runner.addToConfig("use_elf_symbolizer=0");
1379
1380 // Disable compression.
1381 runner.addToConfig("compress=0");
1382
1383 // Set event set.
1384 runner.addToConfig(event_config);
1385
1386 for (const std::string& str : extra_config) {
1387 runner.addToConfig(str);
1388 }
1389
1390 // Create semaphore file
1391 runner.create_semaphore_file();
1392
1393 // Kick off daemon
1394 int daemon_main_return_code = runner.invoke();
1395
1396 // Check return code from daemon
1397 if (0 != daemon_main_return_code) {
1398 return ::testing::AssertionFailure() << "Daemon exited with " << daemon_main_return_code;
1399 }
1400
1401 if (expect_success) {
1402 // Read and decode the resulting perf.data.encoded file
1403 android::perfprofd::PerfprofdRecord encodedProfile;
1404 readEncodedProfile(dest_dir, false, encodedProfile);
1405
1406 // Examine what we get back. Since it's a live profile, we can't
1407 // really do much in terms of verifying the contents.
1408 if (0 == encodedProfile.events_size()) {
1409 return ::testing::AssertionFailure() << "Empty encoded profile.";
1410 }
1411 }
1412
1413 // Verify log contents
1414 return CompareLogMessages(expandVars(expected_log), log_match_exact);
1415 }
1416 };
1417
TEST_F(PerfProfdLiveEventsTest,BasicRunWithLivePerf_Events)1418 TEST_F(PerfProfdLiveEventsTest, BasicRunWithLivePerf_Events)
1419 {
1420 if (!IsPerfSupported()) {
1421 std::cerr << "Test not supported!" << std::endl;
1422 return;
1423 }
1424 const std::string expected = std::string(
1425 "I: starting Android Wide Profiling daemon ") +
1426 "I: config file path set to " + conf_dir + "/perfprofd.conf " +
1427 RAW_RESULT(
1428 I: random seed set to 12345678
1429 I: sleep 674 seconds
1430 I: initiating profile collection
1431 I: sleep 2 seconds
1432 I: profile collection complete
1433 I: sleep 9325 seconds
1434 I: finishing Android Wide Profiling daemon
1435 );
1436 ASSERT_TRUE(SetupAndInvoke("-e_cpu-cycles,page-faults=100000", {}, true, expected, true));
1437 }
1438
TEST_F(PerfProfdLiveEventsTest,BasicRunWithLivePerf_Events_Strip)1439 TEST_F(PerfProfdLiveEventsTest, BasicRunWithLivePerf_Events_Strip)
1440 {
1441 if (!IsPerfSupported()) {
1442 std::cerr << "Test not supported!" << std::endl;
1443 return;
1444 }
1445 const std::string expected = std::string(
1446 "I: starting Android Wide Profiling daemon ") +
1447 "I: config file path set to " + conf_dir + "/perfprofd.conf " +
1448 RAW_RESULT(
1449 I: random seed set to 12345678
1450 I: sleep 674 seconds
1451 I: initiating profile collection
1452 W: Event does:not:exist is unsupported.
1453 I: sleep 2 seconds
1454 I: profile collection complete
1455 I: sleep 9325 seconds
1456 I: finishing Android Wide Profiling daemon
1457 );
1458 ASSERT_TRUE(SetupAndInvoke("-e_cpu-cycles,page-faults,does:not:exist=100000",
1459 { "fail_on_unsupported_events=0" },
1460 true,
1461 expected,
1462 true));
1463 }
1464
TEST_F(PerfProfdLiveEventsTest,BasicRunWithLivePerf_Events_NoStrip)1465 TEST_F(PerfProfdLiveEventsTest, BasicRunWithLivePerf_Events_NoStrip)
1466 {
1467 if (!IsPerfSupported()) {
1468 std::cerr << "Test not supported!" << std::endl;
1469 return;
1470 }
1471 const std::string expected =
1472 RAW_RESULT(
1473 W: Event does:not:exist is unsupported.
1474 W: profile collection failed
1475 );
1476 ASSERT_TRUE(SetupAndInvoke("-e_cpu-cycles,page-faults,does:not:exist=100000",
1477 { "fail_on_unsupported_events=1" },
1478 false,
1479 expected,
1480 false));
1481 }
1482
TEST_F(PerfProfdLiveEventsTest,BasicRunWithLivePerf_EventsGroup)1483 TEST_F(PerfProfdLiveEventsTest, BasicRunWithLivePerf_EventsGroup)
1484 {
1485 if (!IsPerfSupported()) {
1486 std::cerr << "Test not supported!" << std::endl;
1487 return;
1488 }
1489 const std::string expected = std::string(
1490 "I: starting Android Wide Profiling daemon ") +
1491 "I: config file path set to " + conf_dir + "/perfprofd.conf " +
1492 RAW_RESULT(
1493 I: random seed set to 12345678
1494 I: sleep 674 seconds
1495 I: initiating profile collection
1496 I: sleep 2 seconds
1497 I: profile collection complete
1498 I: sleep 9325 seconds
1499 I: finishing Android Wide Profiling daemon
1500 );
1501 ASSERT_TRUE(SetupAndInvoke("-g_cpu-cycles,page-faults=100000", {}, true, expected, true));
1502 }
1503
TEST_F(PerfProfdTest,MultipleRunWithLivePerf)1504 TEST_F(PerfProfdTest, MultipleRunWithLivePerf)
1505 {
1506 if (!IsPerfSupported()) {
1507 std::cerr << "Test not supported!" << std::endl;
1508 return;
1509 }
1510 //
1511 // Basic test to exercise the main loop of the daemon. It includes
1512 // a live 'perf' run
1513 //
1514 PerfProfdRunner runner(conf_dir);
1515 runner.addToConfig("only_debug_build=0");
1516 std::string ddparam("destination_directory="); ddparam += dest_dir;
1517 runner.addToConfig(ddparam);
1518 std::string cfparam("config_directory="); cfparam += conf_dir;
1519 runner.addToConfig(cfparam);
1520 runner.addToConfig("main_loop_iterations=3");
1521 runner.addToConfig("use_fixed_seed=12345678");
1522 runner.addToConfig("collection_interval=9999");
1523 runner.addToConfig("sample_duration=2");
1524 // Avoid the symbolizer for spurious messages.
1525 runner.addToConfig("use_elf_symbolizer=0");
1526
1527 // Disable compression.
1528 runner.addToConfig("compress=0");
1529
1530 runner.write_processed_file(1, 2);
1531
1532 // Create semaphore file
1533 runner.create_semaphore_file();
1534
1535 // Kick off daemon
1536 int daemon_main_return_code = runner.invoke();
1537
1538 // Check return code from daemon
1539 ASSERT_EQ(0, daemon_main_return_code);
1540
1541 // Read and decode the resulting perf.data.encoded file
1542 android::perfprofd::PerfprofdRecord encodedProfile;
1543 readEncodedProfile(dest_dir, false, encodedProfile);
1544
1545 // Examine what we get back. Since it's a live profile, we can't
1546 // really do much in terms of verifying the contents.
1547 EXPECT_LT(0, encodedProfile.events_size());
1548
1549 // Examine that encoded.1 file is removed while encoded.{0|2} exists.
1550 EXPECT_EQ(0, access(encoded_file_path(dest_dir, 0).c_str(), F_OK));
1551 EXPECT_NE(0, access(encoded_file_path(dest_dir, 1).c_str(), F_OK));
1552 EXPECT_EQ(0, access(encoded_file_path(dest_dir, 2).c_str(), F_OK));
1553
1554 // Verify log contents
1555 const std::string expected = std::string(
1556 "I: starting Android Wide Profiling daemon ") +
1557 "I: config file path set to " + conf_dir + "/perfprofd.conf " +
1558 RAW_RESULT(
1559 I: random seed set to 12345678
1560 I: sleep 674 seconds
1561 I: initiating profile collection
1562 I: sleep 2 seconds
1563 I: profile collection complete
1564 I: sleep 9325 seconds
1565 I: sleep 4974 seconds
1566 I: initiating profile collection
1567 I: sleep 2 seconds
1568 I: profile collection complete
1569 I: sleep 5025 seconds
1570 I: sleep 501 seconds
1571 I: initiating profile collection
1572 I: sleep 2 seconds
1573 I: profile collection complete
1574 I: sleep 9498 seconds
1575 I: finishing Android Wide Profiling daemon
1576 );
1577 // check to make sure log excerpt matches
1578 EXPECT_TRUE(CompareLogMessages(expandVars(expected), true));
1579 }
1580
TEST_F(PerfProfdTest,CallChainRunWithLivePerf)1581 TEST_F(PerfProfdTest, CallChainRunWithLivePerf)
1582 {
1583 if (!IsPerfSupported()) {
1584 std::cerr << "Test not supported!" << std::endl;
1585 return;
1586 }
1587 //
1588 // Collect a callchain profile, so as to exercise the code in
1589 // perf_data post-processing that digests callchains.
1590 //
1591 PerfProfdRunner runner(conf_dir);
1592 std::string ddparam("destination_directory="); ddparam += dest_dir;
1593 runner.addToConfig(ddparam);
1594 std::string cfparam("config_directory="); cfparam += conf_dir;
1595 runner.addToConfig(cfparam);
1596 runner.addToConfig("main_loop_iterations=1");
1597 runner.addToConfig("use_fixed_seed=12345678");
1598 runner.addToConfig("max_unprocessed_profiles=100");
1599 runner.addToConfig("collection_interval=9999");
1600 runner.addToConfig("stack_profile=1");
1601 runner.addToConfig("sample_duration=2");
1602 // Avoid the symbolizer for spurious messages.
1603 runner.addToConfig("use_elf_symbolizer=0");
1604
1605 // Disable compression.
1606 runner.addToConfig("compress=0");
1607
1608 // Create semaphore file
1609 runner.create_semaphore_file();
1610
1611 // Kick off daemon
1612 int daemon_main_return_code = runner.invoke();
1613
1614 // Check return code from daemon
1615 ASSERT_EQ(0, daemon_main_return_code);
1616
1617 // Read and decode the resulting perf.data.encoded file
1618 android::perfprofd::PerfprofdRecord encodedProfile;
1619 readEncodedProfile(dest_dir, false, encodedProfile);
1620
1621 // Examine what we get back. Since it's a live profile, we can't
1622 // really do much in terms of verifying the contents.
1623 EXPECT_LT(0, encodedProfile.events_size());
1624
1625 // Verify log contents
1626 const std::string expected = std::string(
1627 "I: starting Android Wide Profiling daemon ") +
1628 "I: config file path set to " + conf_dir + "/perfprofd.conf " +
1629 RAW_RESULT(
1630 I: random seed set to 12345678
1631 I: sleep 674 seconds
1632 I: initiating profile collection
1633 I: sleep 2 seconds
1634 I: profile collection complete
1635 I: sleep 9325 seconds
1636 I: finishing Android Wide Profiling daemon
1637 );
1638 // check to make sure log excerpt matches
1639 EXPECT_TRUE(CompareLogMessages(expandVars(expected), true));
1640
1641 // Check that we have at least one SampleEvent with a callchain.
1642 SampleEventIterator samples(encodedProfile);
1643 bool found_callchain = false;
1644 while (!found_callchain && samples != samples.end()) {
1645 found_callchain = samples->sample_event().callchain_size() > 0;
1646 }
1647 EXPECT_TRUE(found_callchain) << CreateStats(encodedProfile);
1648 }
1649
1650 #endif
1651
1652 class RangeMapTest : public testing::Test {
1653 };
1654
TEST_F(RangeMapTest,TestRangeMap)1655 TEST_F(RangeMapTest, TestRangeMap) {
1656 using namespace android::perfprofd;
1657
1658 RangeMap<std::string, uint64_t> map;
1659 auto print = [&]() {
1660 std::ostringstream oss;
1661 for (auto& aggr_sym : map) {
1662 oss << aggr_sym.first << "#" << aggr_sym.second.symbol;
1663 oss << "[";
1664 for (auto& x : aggr_sym.second.offsets) {
1665 oss << x << ",";
1666 }
1667 oss << "]";
1668 }
1669 return oss.str();
1670 };
1671
1672 EXPECT_STREQ("", print().c_str());
1673
1674 map.Insert("a", 10);
1675 EXPECT_STREQ("10#a[10,]", print().c_str());
1676 map.Insert("a", 100);
1677 EXPECT_STREQ("10#a[10,100,]", print().c_str());
1678 map.Insert("a", 1);
1679 EXPECT_STREQ("1#a[1,10,100,]", print().c_str());
1680 map.Insert("a", 1);
1681 EXPECT_STREQ("1#a[1,10,100,]", print().c_str());
1682 map.Insert("a", 2);
1683 EXPECT_STREQ("1#a[1,2,10,100,]", print().c_str());
1684
1685 map.Insert("b", 200);
1686 EXPECT_STREQ("1#a[1,2,10,100,]200#b[200,]", print().c_str());
1687 map.Insert("b", 199);
1688 EXPECT_STREQ("1#a[1,2,10,100,]199#b[199,200,]", print().c_str());
1689
1690 map.Insert("c", 50);
1691 EXPECT_STREQ("1#a[1,2,10,]50#c[50,]100#a[100,]199#b[199,200,]", print().c_str());
1692 }
1693
1694 class ThreadedHandlerTest : public PerfProfdTest {
1695 public:
SetUp()1696 void SetUp() override {
1697 PerfProfdTest::SetUp();
1698 threaded_handler_.reset(new android::perfprofd::ThreadedHandler());
1699 }
1700
TearDown()1701 void TearDown() override {
1702 threaded_handler_.reset();
1703 PerfProfdTest::TearDown();
1704 }
1705
1706 protected:
1707 std::unique_ptr<android::perfprofd::ThreadedHandler> threaded_handler_;
1708 };
1709
TEST_F(ThreadedHandlerTest,Basic)1710 TEST_F(ThreadedHandlerTest, Basic) {
1711 std::string error_msg;
1712 EXPECT_FALSE(threaded_handler_->StopProfiling(&error_msg));
1713 }
1714
1715 #ifdef __ANDROID__
1716 #define ThreadedHandlerTestName(x) x
1717 #else
1718 #define ThreadedHandlerTestName(x) DISABLED_ ## x
1719 #endif
1720
TEST_F(ThreadedHandlerTest,ThreadedHandlerTestName (Live))1721 TEST_F(ThreadedHandlerTest, ThreadedHandlerTestName(Live)) {
1722 auto config_fn = [](android::perfprofd::ThreadedConfig& config) {
1723 // Use some values that make it likely that things don't fail quickly.
1724 config.main_loop_iterations = 0;
1725 config.collection_interval_in_s = 1000000;
1726 };
1727 std::string error_msg;
1728 ASSERT_TRUE(threaded_handler_->StartProfiling(config_fn, &error_msg)) << error_msg;
1729 EXPECT_TRUE(threaded_handler_->StopProfiling(&error_msg)) << error_msg;
1730 }
1731
main(int argc,char ** argv)1732 int main(int argc, char **argv) {
1733 // Always log to cerr, so that device failures are visible.
1734 android::base::SetLogger(android::base::StderrLogger);
1735
1736 CHECK(android::base::Realpath(argv[0], &gExecutableRealpath));
1737
1738 // switch to / before starting testing (perfprofd
1739 // should be location-independent)
1740 chdir("/");
1741 testing::InitGoogleTest(&argc, argv);
1742 return RUN_ALL_TESTS();
1743 }
1744