2 * Copyright (C) 2015 The Android Open Source Project
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
8 * http://www.apache.org/licenses/LICENSE-2.0
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.
29 #include <sys/types.h>
32 #include <android-base/file.h>
33 #include <android-base/logging.h>
34 #include <android-base/macros.h>
35 #include <android-base/stringprintf.h>
36 #include <android-base/strings.h>
37 #include <android-base/test_utils.h>
38 #include <android-base/thread_annotations.h>
39 #include <gtest/gtest.h>
43 #include "configreader.h"
44 #include "map_utils.h"
45 #include "perfprofdcore.h"
46 #include "perfprofd_cmdline.h"
47 #include "quipper_helper.h"
48 #include "symbolizer.h"
50 #include "perfprofd_record.pb.h"
52 using namespace android::perfprofd::quipper;
54 static_assert(android::base::kEnableDChecks, "Expected DCHECKs to be enabled");
57 // Set to argv[0] on startup
59 static std::string gExecutableRealpath;
63 using android::base::LogId;
64 using android::base::LogSeverity;
69 using namespace std::placeholders;
70 android::base::SetLogger(
71 std::bind(&TestLogHelper::TestLogFunction, this, _1, _2, _3, _4, _5, _6));
74 std::string JoinTestLog(const char* delimiter) {
75 std::unique_lock<std::mutex> ul(lock_);
76 return android::base::Join(test_log_messages_, delimiter);
78 template <typename Predicate>
79 std::string JoinTestLog(const char* delimiter, Predicate pred) {
80 std::unique_lock<std::mutex> ul(lock_);
81 std::vector<std::string> tmp;
82 std::copy_if(test_log_messages_.begin(),
83 test_log_messages_.end(),
84 std::back_inserter(tmp),
86 return android::base::Join(tmp, delimiter);
90 void TestLogFunction(LogId log_id,
95 const char* message) {
96 std::unique_lock<std::mutex> ul(lock_);
97 constexpr char log_characters[] = "VDIWEFF";
98 char severity_char = log_characters[severity];
99 test_log_messages_.push_back(android::base::StringPrintf("%c: %s", severity_char, message));
101 if (severity >= LogSeverity::FATAL_WITHOUT_ABORT) {
102 android::base::StderrLogger(log_id, severity, tag, file, line, message);
109 std::vector<std::string> test_log_messages_;
114 // Path to perf executable on device
115 #define PERFPATH "/system/bin/perf"
117 // Temporary config file that we will emit for the daemon to read
118 #define CONFIGFILE "perfprofd.conf"
120 static bool bothWhiteSpace(char lhs, char rhs)
122 return (std::isspace(lhs) && std::isspace(rhs));
126 // Squeeze out repeated whitespace from expected/actual logs.
128 static std::string squeezeWhite(const std::string &str,
132 if (dump) { fprintf(stderr, "raw %s is %s\n", tag, str.c_str()); }
133 std::string result(str);
134 std::replace(result.begin(), result.end(), '\n', ' ');
135 auto new_end = std::unique(result.begin(), result.end(), bothWhiteSpace);
136 result.erase(new_end, result.end());
137 while (result.begin() != result.end() && std::isspace(*result.rbegin())) {
140 if (dump) { fprintf(stderr, "squeezed %s is %s\n", tag, result.c_str()); }
145 // Replace all occurrences of a string with another string.
147 static std::string replaceAll(const std::string &str,
148 const std::string &from,
149 const std::string &to)
151 std::string ret = "";
153 while (pos < str.size()) {
154 size_t found = str.find(from, pos);
155 if (found == std::string::npos) {
156 ret += str.substr(pos);
159 ret += str.substr(pos, found - pos) + to;
160 pos = found + from.size();
166 // Replace occurrences of special variables in the string.
169 static std::string expandVars(const std::string &str) {
171 return replaceAll(str, "$NATIVE_TESTS", "/data/nativetest64");
173 return replaceAll(str, "$NATIVE_TESTS", "/data/nativetest");
178 class PerfProfdTest : public testing::Test {
180 virtual void SetUp() {
181 test_logger.Install();
185 virtual void TearDown() {
186 android::base::SetLogger(android::base::StderrLogger);
188 // TODO: proper management of test files. For now, use old system() code.
189 for (const auto dir : { &dest_dir, &conf_dir }) {
190 std::string cmd("rm -rf ");
192 int ret = system(cmd.c_str());
199 // Check to see if the log messages emitted by the daemon
200 // match the expected result. By default we use a partial
201 // match, e.g. if we see the expected excerpt anywhere in the
202 // result, it's a match (for exact match, set exact to true)
204 void CompareLogMessages(const std::string& expected,
205 const char* testpoint,
206 bool exactMatch = false) {
207 std::string sqexp = squeezeWhite(expected, "expected");
209 // Strip out JIT errors.
210 std::regex jit_regex("E: Failed to open ELF file: [^ ]*ashmem/dalvik-jit-code-cache.*");
211 auto strip_jit = [&](const std::string& str) {
212 std::smatch jit_match;
213 return !std::regex_match(str, jit_match, jit_regex);
215 std::string sqact = squeezeWhite(test_logger.JoinTestLog(" ", strip_jit), "actual");
218 EXPECT_STREQ(sqexp.c_str(), sqact.c_str());
220 std::size_t foundpos = sqact.find(sqexp);
221 bool wasFound = true;
222 if (foundpos == std::string::npos) {
223 std::cerr << testpoint << ": expected result not found\n";
224 std::cerr << " Actual: \"" << sqact << "\"\n";
225 std::cerr << " Expected: \"" << sqexp << "\"\n";
228 EXPECT_TRUE(wasFound);
232 // test_dir is the directory containing the test executable and
233 // any files associated with the test (will be created by the harness).
234 std::string test_dir;
236 // dest_dir is a temporary directory that we're using as the destination directory.
237 // It is backed by temp_dir1.
238 std::string dest_dir;
240 // conf_dir is a temporary directory that we're using as the configuration directory.
241 // It is backed by temp_dir2.
242 std::string conf_dir;
244 TestLogHelper test_logger;
248 temp_dir1.reset(new TemporaryDir());
249 temp_dir2.reset(new TemporaryDir());
250 dest_dir = temp_dir1->path;
251 conf_dir = temp_dir2->path;
252 test_dir = android::base::Dirname(gExecutableRealpath);
255 std::unique_ptr<TemporaryDir> temp_dir1;
256 std::unique_ptr<TemporaryDir> temp_dir2;
260 /// Helper class to kick off a run of the perfprofd daemon with a specific
263 class PerfProfdRunner {
265 explicit PerfProfdRunner(const std::string& config_dir)
266 : config_dir_(config_dir)
268 config_path_ = config_dir + "/" CONFIGFILE;
273 remove_processed_file();
276 void addToConfig(const std::string &line)
278 config_text_ += line;
279 config_text_ += "\n";
282 void remove_semaphore_file()
284 std::string semaphore(config_dir_);
285 semaphore += "/" SEMAPHORE_FILENAME;
286 unlink(semaphore.c_str());
289 void create_semaphore_file()
291 std::string semaphore(config_dir_);
292 semaphore += "/" SEMAPHORE_FILENAME;
293 close(open(semaphore.c_str(), O_WRONLY|O_CREAT, 0600));
296 void write_processed_file(int start_seq, int end_seq)
298 std::string processed = config_dir_ + "/" PROCESSED_FILENAME;
299 FILE *fp = fopen(processed.c_str(), "w");
300 for (int i = start_seq; i < end_seq; i++) {
301 fprintf(fp, "%d\n", i);
306 void remove_processed_file()
308 std::string processed = config_dir_ + "/" PROCESSED_FILENAME;
309 unlink(processed.c_str());
312 struct LoggingConfig : public Config {
313 void Sleep(size_t seconds) override {
314 // Log sleep calls but don't sleep.
315 LOG(INFO) << "sleep " << seconds << " seconds";
318 bool IsProfilingEnabled() const override {
320 // Check for existence of semaphore file in config directory
322 if (access(config_directory.c_str(), F_OK) == -1) {
323 PLOG(WARNING) << "unable to open config directory " << config_directory;
327 // Check for existence of semaphore file
328 std::string semaphore_filepath = config_directory
329 + "/" + SEMAPHORE_FILENAME;
330 if (access(semaphore_filepath.c_str(), F_OK) == -1) {
340 static const char *argv[3] = { "perfprofd", "-c", "" };
341 argv[2] = config_path_.c_str();
343 writeConfigFile(config_path_, config_text_);
345 // execute daemon main
346 LoggingConfig config;
347 return perfprofd_main(3, (char **) argv, &config);
351 std::string config_dir_;
352 std::string config_path_;
353 std::string config_text_;
355 void writeConfigFile(const std::string &config_path,
356 const std::string &config_text)
358 FILE *fp = fopen(config_path.c_str(), "w");
359 ASSERT_TRUE(fp != nullptr);
360 fprintf(fp, "%s\n", config_text.c_str());
365 //......................................................................
367 static std::string encoded_file_path(const std::string& dest_dir,
369 return android::base::StringPrintf("%s/perf.data.encoded.%d",
370 dest_dir.c_str(), seq);
373 static void readEncodedProfile(const std::string& dest_dir,
375 android::perfprofd::PerfprofdRecord& encodedProfile)
378 int perf_data_stat_result = stat(encoded_file_path(dest_dir, 0).c_str(), &statb);
379 ASSERT_NE(-1, perf_data_stat_result);
383 encoded.resize(statb.st_size);
384 FILE *ifp = fopen(encoded_file_path(dest_dir, 0).c_str(), "r");
385 ASSERT_NE(nullptr, ifp);
386 size_t items_read = fread((void*) encoded.data(), statb.st_size, 1, ifp);
387 ASSERT_EQ(1, items_read);
391 if (compressed && !encoded.empty()) {
393 stream.zalloc = Z_NULL;
394 stream.zfree = Z_NULL;
395 stream.opaque = Z_NULL;
398 constexpr int kWindowBits = 15;
399 constexpr int kGzipEncoding = 16;
400 int init_result = inflateInit2(&stream, kWindowBits | kGzipEncoding);
401 if (init_result != Z_OK) {
402 LOG(ERROR) << "Could not initialize libz stream " << init_result;
408 buf.reserve(2 * encoded.size());
409 stream.avail_in = encoded.size();
410 stream.next_in = reinterpret_cast<Bytef*>(const_cast<char*>(encoded.data()));
415 stream.next_out = static_cast<Bytef*>(chunk);
416 stream.avail_out = arraysize(chunk);
418 result = inflate(&stream, 0);
419 const size_t amount = arraysize(chunk) - stream.avail_out;
421 if (buf.capacity() - buf.size() < amount) {
422 buf.reserve(buf.capacity() + 64u * 1024u);
423 CHECK_LE(amount, buf.capacity() - buf.size());
425 size_t index = buf.size();
426 buf.resize(buf.size() + amount);
427 memcpy(reinterpret_cast<uint8_t*>(const_cast<char*>(buf.data())) + index, chunk, amount);
429 } while (result == Z_OK);
431 if (result != Z_STREAM_END) {
432 LOG(ERROR) << "Finished with not-Z_STREAM_END " << result;
439 encodedProfile.ParseFromString(encoded);
442 #define RAW_RESULT(x) #x
444 TEST_F(PerfProfdTest, TestUtil)
446 EXPECT_EQ("", replaceAll("", "", ""));
447 EXPECT_EQ("zzbc", replaceAll("abc", "a", "zz"));
448 EXPECT_EQ("azzc", replaceAll("abc", "b", "zz"));
449 EXPECT_EQ("abzz", replaceAll("abc", "c", "zz"));
450 EXPECT_EQ("xxyyzz", replaceAll("abc", "abc", "xxyyzz"));
453 TEST_F(PerfProfdTest, MissingGMS)
456 // AWP requires cooperation between the daemon and the GMS core
457 // piece. If we're running on a device that has an old or damaged
458 // version of GMS core, then the config directory we're interested in
459 // may not be there. This test insures that the daemon does the
460 // right thing in this case.
462 PerfProfdRunner runner(conf_dir);
463 runner.addToConfig("only_debug_build=0");
464 runner.addToConfig("trace_config_read=0");
465 runner.addToConfig("config_directory=/does/not/exist");
466 runner.addToConfig("main_loop_iterations=1");
467 runner.addToConfig("use_fixed_seed=1");
468 runner.addToConfig("collection_interval=100");
471 int daemon_main_return_code = runner.invoke();
473 // Check return code from daemon
474 EXPECT_EQ(0, daemon_main_return_code);
476 // Verify log contents
477 const std::string expected = RAW_RESULT(
479 W: unable to open config directory /does/not/exist: No such file or directory
480 I: profile collection skipped (missing config directory)
483 // check to make sure entire log matches
484 CompareLogMessages(expected, "MissingGMS");
488 TEST_F(PerfProfdTest, MissingOptInSemaphoreFile)
491 // Android device owners must opt in to "collect and report usage
492 // data" in order for us to be able to collect profiles. The opt-in
493 // check is performed in the GMS core component; if the check
494 // passes, then it creates a semaphore file for the daemon to pick
497 PerfProfdRunner runner(conf_dir);
498 runner.addToConfig("only_debug_build=0");
499 std::string cfparam("config_directory="); cfparam += conf_dir;
500 runner.addToConfig(cfparam);
501 std::string ddparam("destination_directory="); ddparam += dest_dir;
502 runner.addToConfig(ddparam);
503 runner.addToConfig("main_loop_iterations=1");
504 runner.addToConfig("use_fixed_seed=1");
505 runner.addToConfig("collection_interval=100");
507 runner.remove_semaphore_file();
510 int daemon_main_return_code = runner.invoke();
512 // Check return code from daemon
513 EXPECT_EQ(0, daemon_main_return_code);
515 // Verify log contents
516 const std::string expected = RAW_RESULT(
517 I: profile collection skipped (missing config directory)
519 // check to make sure log excerpt matches
520 CompareLogMessages(expected, "MissingOptInSemaphoreFile");
523 TEST_F(PerfProfdTest, MissingPerfExecutable)
526 // Perfprofd uses the 'simpleperf' tool to collect profiles
527 // (although this may conceivably change in the future). This test
528 // checks to make sure that if 'simpleperf' is not present we bail out
529 // from collecting profiles.
531 PerfProfdRunner runner(conf_dir);
532 runner.addToConfig("only_debug_build=0");
533 runner.addToConfig("trace_config_read=1");
534 std::string cfparam("config_directory="); cfparam += conf_dir;
535 runner.addToConfig(cfparam);
536 std::string ddparam("destination_directory="); ddparam += dest_dir;
537 runner.addToConfig(ddparam);
538 runner.addToConfig("main_loop_iterations=1");
539 runner.addToConfig("use_fixed_seed=1");
540 runner.addToConfig("collection_interval=100");
541 runner.addToConfig("perf_path=/does/not/exist");
543 // Create semaphore file
544 runner.create_semaphore_file();
547 int daemon_main_return_code = runner.invoke();
549 // Check return code from daemon
550 EXPECT_EQ(0, daemon_main_return_code);
552 // expected log contents
553 const std::string expected = RAW_RESULT(
554 I: profile collection skipped (missing 'perf' executable)
556 // check to make sure log excerpt matches
557 CompareLogMessages(expected, "MissingPerfExecutable");
560 TEST_F(PerfProfdTest, BadPerfRun)
563 // Perf tools tend to be tightly coupled with a specific kernel
564 // version -- if things are out of sync perf could fail or
565 // crash. This test makes sure that we detect such a case and log
568 PerfProfdRunner runner(conf_dir);
569 runner.addToConfig("only_debug_build=0");
570 std::string cfparam("config_directory="); cfparam += conf_dir;
571 runner.addToConfig(cfparam);
572 std::string ddparam("destination_directory="); ddparam += dest_dir;
573 runner.addToConfig(ddparam);
574 runner.addToConfig("main_loop_iterations=1");
575 runner.addToConfig("use_fixed_seed=1");
576 runner.addToConfig("collection_interval=100");
578 runner.addToConfig("perf_path=/system/bin/false");
580 runner.addToConfig("perf_path=/bin/false");
583 // Create semaphore file
584 runner.create_semaphore_file();
587 int daemon_main_return_code = runner.invoke();
589 // Check return code from daemon
590 EXPECT_EQ(0, daemon_main_return_code);
592 // Verify log contents
593 const std::string expected = RAW_RESULT(
594 W: perf bad exit status 1
595 W: profile collection failed
598 // check to make sure log excerpt matches
599 CompareLogMessages(expected, "BadPerfRun");
602 TEST_F(PerfProfdTest, ConfigFileParsing)
605 // Gracefully handly malformed items in the config file
607 PerfProfdRunner runner(conf_dir);
608 runner.addToConfig("only_debug_build=0");
609 runner.addToConfig("main_loop_iterations=1");
610 runner.addToConfig("collection_interval=100");
611 runner.addToConfig("use_fixed_seed=1");
612 runner.addToConfig("destination_directory=/does/not/exist");
614 // assorted bad syntax
615 runner.addToConfig("collection_interval=0");
616 runner.addToConfig("collection_interval=-1");
617 runner.addToConfig("collection_interval=2");
618 runner.addToConfig("nonexistent_key=something");
619 runner.addToConfig("no_equals_stmt");
622 int daemon_main_return_code = runner.invoke();
624 // Check return code from daemon
625 EXPECT_EQ(0, daemon_main_return_code);
627 // Verify log contents
628 const std::string expected = RAW_RESULT(
629 W: line 6: specified value 0 for 'collection_interval' outside permitted range [100 4294967295] (ignored)
630 W: line 7: malformed unsigned value (ignored)
631 W: line 8: specified value 2 for 'collection_interval' outside permitted range [100 4294967295] (ignored)
632 W: line 9: unknown option 'nonexistent_key' ignored
633 W: line 10: line malformed (no '=' found)
636 // check to make sure log excerpt matches
637 CompareLogMessages(expected, "ConfigFileParsing");
640 TEST_F(PerfProfdTest, ProfileCollectionAnnotations)
642 unsigned util1 = collect_cpu_utilization();
643 EXPECT_LE(util1, 100);
646 // NB: expectation is that when we run this test, the device will be
647 // completed booted, will be on charger, and will not have the camera
649 EXPECT_FALSE(get_booting());
651 EXPECT_TRUE(get_charging());
653 EXPECT_FALSE(get_camera_active());
658 template <typename Iterator>
659 size_t CountEvents(const quipper::PerfDataProto& proto) {
661 for (Iterator it(proto); it != it.end(); ++it) {
667 size_t CountCommEvents(const quipper::PerfDataProto& proto) {
668 return CountEvents<CommEventIterator>(proto);
670 size_t CountMmapEvents(const quipper::PerfDataProto& proto) {
671 return CountEvents<MmapEventIterator>(proto);
673 size_t CountSampleEvents(const quipper::PerfDataProto& proto) {
674 return CountEvents<SampleEventIterator>(proto);
676 size_t CountForkEvents(const quipper::PerfDataProto& proto) {
677 return CountEvents<ForkEventIterator>(proto);
679 size_t CountExitEvents(const quipper::PerfDataProto& proto) {
680 return CountEvents<ExitEventIterator>(proto);
683 std::string CreateStats(const quipper::PerfDataProto& proto) {
684 std::ostringstream oss;
685 oss << "Mmap events: " << CountMmapEvents(proto) << std::endl;
686 oss << "Sample events: " << CountSampleEvents(proto) << std::endl;
687 oss << "Comm events: " << CountCommEvents(proto) << std::endl;
688 oss << "Fork events: " << CountForkEvents(proto) << std::endl;
689 oss << "Exit events: " << CountExitEvents(proto) << std::endl;
693 std::string FormatSampleEvent(const quipper::PerfDataProto_SampleEvent& sample) {
694 std::ostringstream oss;
695 if (sample.has_pid()) {
696 oss << "pid=" << sample.pid();
698 if (sample.has_tid()) {
699 oss << " tid=" << sample.tid();
701 if (sample.has_ip()) {
702 oss << " ip=" << sample.ip();
704 if (sample.has_addr()) {
705 oss << " addr=" << sample.addr();
707 if (sample.callchain_size() > 0) {
708 oss << " callchain=";
709 for (uint64_t cc : sample.callchain()) {
718 struct BasicRunWithCannedPerf : PerfProfdTest {
719 void VerifyBasicCannedProfile(const android::perfprofd::PerfprofdRecord& encodedProfile) {
720 ASSERT_TRUE(encodedProfile.has_perf_data()) << test_logger.JoinTestLog(" ");
721 const quipper::PerfDataProto& perf_data = encodedProfile.perf_data();
723 // Expect 21108 events.
724 EXPECT_EQ(21108, perf_data.events_size()) << CreateStats(perf_data);
726 EXPECT_EQ(48, CountMmapEvents(perf_data)) << CreateStats(perf_data);
727 EXPECT_EQ(19986, CountSampleEvents(perf_data)) << CreateStats(perf_data);
728 EXPECT_EQ(1033, CountCommEvents(perf_data)) << CreateStats(perf_data);
729 EXPECT_EQ(15, CountForkEvents(perf_data)) << CreateStats(perf_data);
730 EXPECT_EQ(26, CountExitEvents(perf_data)) << CreateStats(perf_data);
732 if (HasNonfatalFailure()) {
737 MmapEventIterator mmap(perf_data);
738 constexpr std::pair<const char*, uint64_t> kMmapEvents[] = {
739 std::make_pair("[kernel.kallsyms]_text", 0),
740 std::make_pair("/system/lib/libc.so", 3067412480u),
741 std::make_pair("/system/vendor/lib/libdsutils.so", 3069911040u),
742 std::make_pair("/system/lib/libc.so", 3067191296u),
743 std::make_pair("/system/lib/libc++.so", 3069210624u),
744 std::make_pair("/data/dalvik-cache/arm/system@framework@boot.oat", 1900048384u),
745 std::make_pair("/system/lib/libjavacore.so", 2957135872u),
746 std::make_pair("/system/vendor/lib/libqmi_encdec.so", 3006644224u),
747 std::make_pair("/data/dalvik-cache/arm/system@framework@wifi-service.jar@classes.dex",
749 std::make_pair("/system/lib/libart.so", 3024150528u),
750 std::make_pair("/system/lib/libz.so", 3056410624u),
751 std::make_pair("/system/lib/libicui18n.so", 3057610752u),
753 for (auto& pair : kMmapEvents) {
754 EXPECT_STREQ(pair.first, mmap->mmap_event().filename().c_str());
755 EXPECT_EQ(pair.second, mmap->mmap_event().start()) << pair.first;
761 CommEventIterator comm(perf_data);
762 constexpr const char* kCommEvents[] = {
763 "init", "kthreadd", "ksoftirqd/0", "kworker/u:0H", "migration/0", "khelper",
764 "netns", "modem_notifier", "smd_channel_clo", "smsm_cb_wq", "rpm-smd", "kworker/u:1H",
766 for (auto str : kCommEvents) {
767 EXPECT_STREQ(str, comm->comm_event().comm().c_str());
773 SampleEventIterator samples(perf_data);
774 constexpr const char* kSampleEvents[] = {
775 "pid=0 tid=0 ip=3222720196",
776 "pid=0 tid=0 ip=3222910876",
777 "pid=0 tid=0 ip=3222910876",
778 "pid=0 tid=0 ip=3222910876",
779 "pid=0 tid=0 ip=3222910876",
780 "pid=0 tid=0 ip=3222910876",
781 "pid=0 tid=0 ip=3222910876",
782 "pid=3 tid=3 ip=3231975108",
783 "pid=5926 tid=5926 ip=3231964952",
784 "pid=5926 tid=5926 ip=3225342428",
785 "pid=5926 tid=5926 ip=3223841448",
786 "pid=5926 tid=5926 ip=3069807920",
788 for (auto str : kSampleEvents) {
789 EXPECT_STREQ(str, FormatSampleEvent(samples->sample_event()).c_str());
793 // Skip some samples.
794 for (size_t i = 0; i != 5000; ++i) {
797 constexpr const char* kSampleEvents2[] = {
798 "pid=5938 tid=5938 ip=3069630992",
799 "pid=5938 tid=5938 ip=3069626616",
800 "pid=5938 tid=5938 ip=3069626636",
801 "pid=5938 tid=5938 ip=3069637212",
802 "pid=5938 tid=5938 ip=3069637208",
803 "pid=5938 tid=5938 ip=3069637252",
804 "pid=5938 tid=5938 ip=3069346040",
805 "pid=5938 tid=5938 ip=3069637128",
806 "pid=5938 tid=5938 ip=3069626616",
808 for (auto str : kSampleEvents2) {
809 EXPECT_STREQ(str, FormatSampleEvent(samples->sample_event()).c_str());
813 // Skip some samples.
814 for (size_t i = 0; i != 5000; ++i) {
817 constexpr const char* kSampleEvents3[] = {
818 "pid=5938 tid=5938 ip=3069912036",
819 "pid=5938 tid=5938 ip=3069637260",
820 "pid=5938 tid=5938 ip=3069631024",
821 "pid=5938 tid=5938 ip=3069346064",
822 "pid=5938 tid=5938 ip=3069637356",
823 "pid=5938 tid=5938 ip=3069637144",
824 "pid=5938 tid=5938 ip=3069912036",
825 "pid=5938 tid=5938 ip=3069912036",
826 "pid=5938 tid=5938 ip=3069631244",
828 for (auto str : kSampleEvents3) {
829 EXPECT_STREQ(str, FormatSampleEvent(samples->sample_event()).c_str());
836 TEST_F(BasicRunWithCannedPerf, Basic)
839 // Verify the portion of the daemon that reads and encodes
840 // perf.data files. Here we run the encoder on a canned perf.data
841 // file and verify that the resulting protobuf contains what
842 // we think it should contain.
844 std::string input_perf_data(test_dir);
845 input_perf_data += "/canned.perf.data";
847 // Set up config to avoid these annotations (they are tested elsewhere)
848 ConfigReader config_reader;
849 config_reader.overrideUnsignedEntry("collect_cpu_utilization", 0);
850 config_reader.overrideUnsignedEntry("collect_charging_state", 0);
851 config_reader.overrideUnsignedEntry("collect_camera_active", 0);
853 // Disable compression.
854 config_reader.overrideUnsignedEntry("compress", 0);
856 PerfProfdRunner::LoggingConfig config;
857 config_reader.FillConfig(&config);
859 // Kick off encoder and check return code
860 PROFILE_RESULT result =
861 encode_to_proto(input_perf_data, encoded_file_path(dest_dir, 0).c_str(), config, 0, nullptr);
862 ASSERT_EQ(OK_PROFILE_COLLECTION, result) << test_logger.JoinTestLog(" ");
864 // Read and decode the resulting perf.data.encoded file
865 android::perfprofd::PerfprofdRecord encodedProfile;
866 readEncodedProfile(dest_dir, false, encodedProfile);
868 VerifyBasicCannedProfile(encodedProfile);
871 TEST_F(BasicRunWithCannedPerf, Compressed)
874 // Verify the portion of the daemon that reads and encodes
875 // perf.data files. Here we run the encoder on a canned perf.data
876 // file and verify that the resulting protobuf contains what
877 // we think it should contain.
879 std::string input_perf_data(test_dir);
880 input_perf_data += "/canned.perf.data";
882 // Set up config to avoid these annotations (they are tested elsewhere)
883 ConfigReader config_reader;
884 config_reader.overrideUnsignedEntry("collect_cpu_utilization", 0);
885 config_reader.overrideUnsignedEntry("collect_charging_state", 0);
886 config_reader.overrideUnsignedEntry("collect_camera_active", 0);
888 // Enable compression.
889 config_reader.overrideUnsignedEntry("compress", 1);
891 PerfProfdRunner::LoggingConfig config;
892 config_reader.FillConfig(&config);
894 // Kick off encoder and check return code
895 PROFILE_RESULT result =
896 encode_to_proto(input_perf_data, encoded_file_path(dest_dir, 0).c_str(), config, 0, nullptr);
897 ASSERT_EQ(OK_PROFILE_COLLECTION, result) << test_logger.JoinTestLog(" ");
899 // Read and decode the resulting perf.data.encoded file
900 android::perfprofd::PerfprofdRecord encodedProfile;
901 readEncodedProfile(dest_dir, true, encodedProfile);
903 VerifyBasicCannedProfile(encodedProfile);
906 TEST_F(BasicRunWithCannedPerf, WithSymbolizer)
909 // Verify the portion of the daemon that reads and encodes
910 // perf.data files. Here we run the encoder on a canned perf.data
911 // file and verify that the resulting protobuf contains what
912 // we think it should contain.
914 std::string input_perf_data(test_dir);
915 input_perf_data += "/canned.perf.data";
917 // Set up config to avoid these annotations (they are tested elsewhere)
918 ConfigReader config_reader;
919 config_reader.overrideUnsignedEntry("collect_cpu_utilization", 0);
920 config_reader.overrideUnsignedEntry("collect_charging_state", 0);
921 config_reader.overrideUnsignedEntry("collect_camera_active", 0);
923 // Disable compression.
924 config_reader.overrideUnsignedEntry("compress", 0);
926 PerfProfdRunner::LoggingConfig config;
927 config_reader.FillConfig(&config);
929 // Kick off encoder and check return code
930 struct TestSymbolizer : public perfprofd::Symbolizer {
931 std::string Decode(const std::string& dso, uint64_t address) override {
932 return dso + "@" + std::to_string(address);
934 bool GetMinExecutableVAddr(const std::string& dso, uint64_t* addr) override {
939 TestSymbolizer test_symbolizer;
940 PROFILE_RESULT result =
941 encode_to_proto(input_perf_data,
942 encoded_file_path(dest_dir, 0).c_str(),
946 ASSERT_EQ(OK_PROFILE_COLLECTION, result);
948 // Read and decode the resulting perf.data.encoded file
949 android::perfprofd::PerfprofdRecord encodedProfile;
950 readEncodedProfile(dest_dir, false, encodedProfile);
952 VerifyBasicCannedProfile(encodedProfile);
954 auto find_symbol = [&](const std::string& filename)
955 -> const android::perfprofd::PerfprofdRecord_SymbolInfo* {
956 for (auto& symbol_info : encodedProfile.symbol_info()) {
957 if (symbol_info.filename() == filename) {
963 auto all_filenames = [&]() {
964 std::ostringstream oss;
965 for (auto& symbol_info : encodedProfile.symbol_info()) {
966 oss << " " << symbol_info.filename();
971 EXPECT_TRUE(find_symbol("/data/app/com.google.android.apps.plus-1/lib/arm/libcronet.so")
972 != nullptr) << all_filenames() << test_logger.JoinTestLog("\n");
973 EXPECT_TRUE(find_symbol("/data/dalvik-cache/arm/system@framework@wifi-service.jar@classes.dex")
974 != nullptr) << all_filenames();
975 EXPECT_TRUE(find_symbol("/data/dalvik-cache/arm/data@app@com.google.android.gms-2@base.apk@"
977 != nullptr) << all_filenames();
978 EXPECT_TRUE(find_symbol("/data/dalvik-cache/arm/system@framework@boot.oat") != nullptr)
982 TEST_F(PerfProfdTest, CallchainRunWithCannedPerf)
984 // This test makes sure that the perf.data converter
985 // can handle call chains.
987 std::string input_perf_data(test_dir);
988 input_perf_data += "/callchain.canned.perf.data";
990 // Set up config to avoid these annotations (they are tested elsewhere)
991 ConfigReader config_reader;
992 config_reader.overrideUnsignedEntry("collect_cpu_utilization", 0);
993 config_reader.overrideUnsignedEntry("collect_charging_state", 0);
994 config_reader.overrideUnsignedEntry("collect_camera_active", 0);
996 // Disable compression.
997 config_reader.overrideUnsignedEntry("compress", 0);
999 PerfProfdRunner::LoggingConfig config;
1000 config_reader.FillConfig(&config);
1002 // Kick off encoder and check return code
1003 PROFILE_RESULT result =
1004 encode_to_proto(input_perf_data, encoded_file_path(dest_dir, 0).c_str(), config, 0, nullptr);
1005 ASSERT_EQ(OK_PROFILE_COLLECTION, result);
1007 // Read and decode the resulting perf.data.encoded file
1008 android::perfprofd::PerfprofdRecord encodedProfile;
1009 readEncodedProfile(dest_dir, false, encodedProfile);
1012 ASSERT_TRUE(encodedProfile.has_perf_data());
1013 const quipper::PerfDataProto& perf_data = encodedProfile.perf_data();
1015 // Expect 21108 events.
1016 EXPECT_EQ(2224, perf_data.events_size()) << CreateStats(perf_data);
1019 SampleEventIterator samples(perf_data);
1020 constexpr const char* kSampleEvents[] = {
1021 "0: pid=6225 tid=6225 ip=18446743798834668032 callchain=->18446744073709551488->"
1022 "18446743798834668032->18446743798834782596->18446743798834784624->"
1023 "18446743798835055136->18446743798834788016->18446743798834789192->"
1024 "18446743798834789512->18446743798834790216->18446743798833756776",
1025 "1: pid=6225 tid=6225 ip=18446743798835685700 callchain=->18446744073709551488->"
1026 "18446743798835685700->18446743798835688704->18446743798835650964->"
1027 "18446743798834612104->18446743798834612276->18446743798835055528->"
1028 "18446743798834788016->18446743798834789192->18446743798834789512->"
1029 "18446743798834790216->18446743798833756776",
1030 "2: pid=6225 tid=6225 ip=18446743798835055804 callchain=->18446744073709551488->"
1031 "18446743798835055804->18446743798834788016->18446743798834789192->"
1032 "18446743798834789512->18446743798834790216->18446743798833756776",
1033 "3: pid=6225 tid=6225 ip=18446743798835991212 callchain=->18446744073709551488->"
1034 "18446743798835991212->18446743798834491060->18446743798834675572->"
1035 "18446743798834676516->18446743798834612172->18446743798834612276->"
1036 "18446743798835056664->18446743798834788016->18446743798834789192->"
1037 "18446743798834789512->18446743798834790216->18446743798833756776",
1038 "4: pid=6225 tid=6225 ip=18446743798844881108 callchain=->18446744073709551488->"
1039 "18446743798844881108->18446743798834836140->18446743798834846384->"
1040 "18446743798834491100->18446743798834675572->18446743798834676516->"
1041 "18446743798834612172->18446743798834612276->18446743798835056784->"
1042 "18446743798834788016->18446743798834789192->18446743798834789512->"
1043 "18446743798834790216->18446743798833756776",
1045 size_t cmp_index = 0;
1046 for (size_t index = 0; samples != samples.end(); ++samples, ++index) {
1047 if (samples->sample_event().callchain_size() > 0) {
1048 std::ostringstream oss;
1049 oss << index << ": " << FormatSampleEvent(samples->sample_event());
1050 EXPECT_STREQ(kSampleEvents[cmp_index], oss.str().c_str());
1052 if (cmp_index == arraysize(kSampleEvents)) {
1062 TEST_F(PerfProfdTest, BasicRunWithLivePerf)
1065 // Basic test to exercise the main loop of the daemon. It includes
1066 // a live 'perf' run
1068 PerfProfdRunner runner(conf_dir);
1069 runner.addToConfig("only_debug_build=0");
1070 std::string ddparam("destination_directory="); ddparam += dest_dir;
1071 runner.addToConfig(ddparam);
1072 std::string cfparam("config_directory="); cfparam += conf_dir;
1073 runner.addToConfig(cfparam);
1074 runner.addToConfig("main_loop_iterations=1");
1075 runner.addToConfig("use_fixed_seed=12345678");
1076 runner.addToConfig("max_unprocessed_profiles=100");
1077 runner.addToConfig("collection_interval=9999");
1078 runner.addToConfig("sample_duration=2");
1079 // Avoid the symbolizer for spurious messages.
1080 runner.addToConfig("use_elf_symbolizer=0");
1082 // Disable compression.
1083 runner.addToConfig("compress=0");
1085 // Create semaphore file
1086 runner.create_semaphore_file();
1089 int daemon_main_return_code = runner.invoke();
1091 // Check return code from daemon
1092 ASSERT_EQ(0, daemon_main_return_code);
1094 // Read and decode the resulting perf.data.encoded file
1095 android::perfprofd::PerfprofdRecord encodedProfile;
1096 readEncodedProfile(dest_dir, false, encodedProfile);
1098 // Examine what we get back. Since it's a live profile, we can't
1099 // really do much in terms of verifying the contents.
1100 EXPECT_LT(0, encodedProfile.perf_data().events_size());
1102 // Verify log contents
1103 const std::string expected = std::string(
1104 "I: starting Android Wide Profiling daemon ") +
1105 "I: config file path set to " + conf_dir + "/perfprofd.conf " +
1107 I: random seed set to 12345678
1108 I: sleep 674 seconds
1109 I: initiating profile collection
1111 I: profile collection complete
1112 I: sleep 9325 seconds
1113 I: finishing Android Wide Profiling daemon
1115 // check to make sure log excerpt matches
1116 CompareLogMessages(expandVars(expected), "BasicRunWithLivePerf", true);
1119 TEST_F(PerfProfdTest, MultipleRunWithLivePerf)
1122 // Basic test to exercise the main loop of the daemon. It includes
1123 // a live 'perf' run
1125 PerfProfdRunner runner(conf_dir);
1126 runner.addToConfig("only_debug_build=0");
1127 std::string ddparam("destination_directory="); ddparam += dest_dir;
1128 runner.addToConfig(ddparam);
1129 std::string cfparam("config_directory="); cfparam += conf_dir;
1130 runner.addToConfig(cfparam);
1131 runner.addToConfig("main_loop_iterations=3");
1132 runner.addToConfig("use_fixed_seed=12345678");
1133 runner.addToConfig("collection_interval=9999");
1134 runner.addToConfig("sample_duration=2");
1135 // Avoid the symbolizer for spurious messages.
1136 runner.addToConfig("use_elf_symbolizer=0");
1138 // Disable compression.
1139 runner.addToConfig("compress=0");
1141 runner.write_processed_file(1, 2);
1143 // Create semaphore file
1144 runner.create_semaphore_file();
1147 int daemon_main_return_code = runner.invoke();
1149 // Check return code from daemon
1150 ASSERT_EQ(0, daemon_main_return_code);
1152 // Read and decode the resulting perf.data.encoded file
1153 android::perfprofd::PerfprofdRecord encodedProfile;
1154 readEncodedProfile(dest_dir, false, encodedProfile);
1156 // Examine what we get back. Since it's a live profile, we can't
1157 // really do much in terms of verifying the contents.
1158 EXPECT_LT(0, encodedProfile.perf_data().events_size());
1160 // Examine that encoded.1 file is removed while encoded.{0|2} exists.
1161 EXPECT_EQ(0, access(encoded_file_path(dest_dir, 0).c_str(), F_OK));
1162 EXPECT_NE(0, access(encoded_file_path(dest_dir, 1).c_str(), F_OK));
1163 EXPECT_EQ(0, access(encoded_file_path(dest_dir, 2).c_str(), F_OK));
1165 // Verify log contents
1166 const std::string expected = std::string(
1167 "I: starting Android Wide Profiling daemon ") +
1168 "I: config file path set to " + conf_dir + "/perfprofd.conf " +
1170 I: random seed set to 12345678
1171 I: sleep 674 seconds
1172 I: initiating profile collection
1174 I: profile collection complete
1175 I: sleep 9325 seconds
1176 I: sleep 4974 seconds
1177 I: initiating profile collection
1179 I: profile collection complete
1180 I: sleep 5025 seconds
1181 I: sleep 501 seconds
1182 I: initiating profile collection
1184 I: profile collection complete
1185 I: sleep 9498 seconds
1186 I: finishing Android Wide Profiling daemon
1188 // check to make sure log excerpt matches
1189 CompareLogMessages(expandVars(expected), "BasicRunWithLivePerf", true);
1192 TEST_F(PerfProfdTest, CallChainRunWithLivePerf)
1195 // Collect a callchain profile, so as to exercise the code in
1196 // perf_data post-processing that digests callchains.
1198 PerfProfdRunner runner(conf_dir);
1199 std::string ddparam("destination_directory="); ddparam += dest_dir;
1200 runner.addToConfig(ddparam);
1201 std::string cfparam("config_directory="); cfparam += conf_dir;
1202 runner.addToConfig(cfparam);
1203 runner.addToConfig("main_loop_iterations=1");
1204 runner.addToConfig("use_fixed_seed=12345678");
1205 runner.addToConfig("max_unprocessed_profiles=100");
1206 runner.addToConfig("collection_interval=9999");
1207 runner.addToConfig("stack_profile=1");
1208 runner.addToConfig("sample_duration=2");
1209 // Avoid the symbolizer for spurious messages.
1210 runner.addToConfig("use_elf_symbolizer=0");
1212 // Disable compression.
1213 runner.addToConfig("compress=0");
1215 // Create semaphore file
1216 runner.create_semaphore_file();
1219 int daemon_main_return_code = runner.invoke();
1221 // Check return code from daemon
1222 ASSERT_EQ(0, daemon_main_return_code);
1224 // Read and decode the resulting perf.data.encoded file
1225 android::perfprofd::PerfprofdRecord encodedProfile;
1226 readEncodedProfile(dest_dir, false, encodedProfile);
1228 // Examine what we get back. Since it's a live profile, we can't
1229 // really do much in terms of verifying the contents.
1230 EXPECT_LT(0, encodedProfile.perf_data().events_size());
1232 // Verify log contents
1233 const std::string expected = std::string(
1234 "I: starting Android Wide Profiling daemon ") +
1235 "I: config file path set to " + conf_dir + "/perfprofd.conf " +
1237 I: random seed set to 12345678
1238 I: sleep 674 seconds
1239 I: initiating profile collection
1241 I: profile collection complete
1242 I: sleep 9325 seconds
1243 I: finishing Android Wide Profiling daemon
1245 // check to make sure log excerpt matches
1246 CompareLogMessages(expandVars(expected), "CallChainRunWithLivePerf", true);
1248 // Check that we have at least one SampleEvent with a callchain.
1249 SampleEventIterator samples(encodedProfile.perf_data());
1250 bool found_callchain = false;
1251 while (!found_callchain && samples != samples.end()) {
1252 found_callchain = samples->sample_event().callchain_size() > 0;
1254 EXPECT_TRUE(found_callchain) << CreateStats(encodedProfile.perf_data());
1259 class RangeMapTest : public testing::Test {
1262 TEST_F(RangeMapTest, TestRangeMap) {
1263 using namespace android::perfprofd;
1265 RangeMap<std::string, uint64_t> map;
1266 auto print = [&]() {
1267 std::ostringstream oss;
1268 for (auto& aggr_sym : map) {
1269 oss << aggr_sym.first << "#" << aggr_sym.second.symbol;
1271 for (auto& x : aggr_sym.second.offsets) {
1279 EXPECT_STREQ("", print().c_str());
1281 map.Insert("a", 10);
1282 EXPECT_STREQ("10#a[10,]", print().c_str());
1283 map.Insert("a", 100);
1284 EXPECT_STREQ("10#a[10,100,]", print().c_str());
1286 EXPECT_STREQ("1#a[1,10,100,]", print().c_str());
1288 EXPECT_STREQ("1#a[1,10,100,]", print().c_str());
1290 EXPECT_STREQ("1#a[1,2,10,100,]", print().c_str());
1292 map.Insert("b", 200);
1293 EXPECT_STREQ("1#a[1,2,10,100,]200#b[200,]", print().c_str());
1294 map.Insert("b", 199);
1295 EXPECT_STREQ("1#a[1,2,10,100,]199#b[199,200,]", print().c_str());
1297 map.Insert("c", 50);
1298 EXPECT_STREQ("1#a[1,2,10,]50#c[50,]100#a[100,]199#b[199,200,]", print().c_str());
1301 int main(int argc, char **argv) {
1302 // Always log to cerr, so that device failures are visible.
1303 android::base::SetLogger(android::base::StderrLogger);
1305 CHECK(android::base::Realpath(argv[0], &gExecutableRealpath));
1307 // switch to / before starting testing (perfprofd
1308 // should be location-independent)
1310 testing::InitGoogleTest(&argc, argv);
1311 return RUN_ALL_TESTS();