OSDN Git Service

Perfprofd: Add GZIP compression
[android-x86/system-extras.git] / perfprofd / tests / perfprofd_test.cc
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
26 #include <fcntl.h>
27 #include <stdio.h>
28 #include <libgen.h>
29 #include <sys/types.h>
30 #include <sys/stat.h>
31
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>
40 #include <zlib.h>
41
42 #include "config.h"
43 #include "configreader.h"
44 #include "perfprofdcore.h"
45 #include "quipper_helper.h"
46 #include "symbolizer.h"
47
48 #include "perfprofd_record.pb.h"
49
50 using namespace android::perfprofd::quipper;
51
52 //
53 // Set to argv[0] on startup
54 //
55 static std::string gExecutableRealpath;
56
57 namespace {
58
59 using android::base::LogId;
60 using android::base::LogSeverity;
61
62 class TestLogHelper {
63  public:
64   void Install() {
65     using namespace std::placeholders;
66     android::base::SetLogger(
67         std::bind(&TestLogHelper::TestLogFunction, this, _1, _2, _3, _4, _5, _6));
68   }
69
70   std::string JoinTestLog(const char* delimiter) {
71     std::unique_lock<std::mutex> ul(lock_);
72     return android::base::Join(test_log_messages_, delimiter);
73   }
74   template <typename Predicate>
75   std::string JoinTestLog(const char* delimiter, Predicate pred) {
76     std::unique_lock<std::mutex> ul(lock_);
77     std::vector<std::string> tmp;
78     std::copy_if(test_log_messages_.begin(),
79                  test_log_messages_.end(),
80                  std::back_inserter(tmp),
81                  pred);
82     return android::base::Join(tmp, delimiter);
83   }
84
85  private:
86   void TestLogFunction(LogId log_id ATTRIBUTE_UNUSED,
87                        LogSeverity severity,
88                        const char* tag,
89                        const char* file ATTRIBUTE_UNUSED,
90                        unsigned int line ATTRIBUTE_UNUSED,
91                        const char* message) {
92     std::unique_lock<std::mutex> ul(lock_);
93     constexpr char log_characters[] = "VDIWEFF";
94     char severity_char = log_characters[severity];
95     test_log_messages_.push_back(android::base::StringPrintf("%c: %s", severity_char, message));
96   }
97
98  private:
99   std::mutex lock_;
100
101   std::vector<std::string> test_log_messages_;
102 };
103
104 }  // namespace
105
106 // Path to perf executable on device
107 #define PERFPATH "/system/bin/perf"
108
109 // Temporary config file that we will emit for the daemon to read
110 #define CONFIGFILE "perfprofd.conf"
111
112 static bool bothWhiteSpace(char lhs, char rhs)
113 {
114   return (std::isspace(lhs) && std::isspace(rhs));
115 }
116
117 //
118 // Squeeze out repeated whitespace from expected/actual logs.
119 //
120 static std::string squeezeWhite(const std::string &str,
121                                 const char *tag,
122                                 bool dump=false)
123 {
124   if (dump) { fprintf(stderr, "raw %s is %s\n", tag, str.c_str()); }
125   std::string result(str);
126   std::replace(result.begin(), result.end(), '\n', ' ');
127   auto new_end = std::unique(result.begin(), result.end(), bothWhiteSpace);
128   result.erase(new_end, result.end());
129   while (result.begin() != result.end() && std::isspace(*result.rbegin())) {
130     result.pop_back();
131   }
132   if (dump) { fprintf(stderr, "squeezed %s is %s\n", tag, result.c_str()); }
133   return result;
134 }
135
136 //
137 // Replace all occurrences of a string with another string.
138 //
139 static std::string replaceAll(const std::string &str,
140                               const std::string &from,
141                               const std::string &to)
142 {
143   std::string ret = "";
144   size_t pos = 0;
145   while (pos < str.size()) {
146     size_t found = str.find(from, pos);
147     if (found == std::string::npos) {
148       ret += str.substr(pos);
149       break;
150     }
151     ret += str.substr(pos, found - pos) + to;
152     pos = found + from.size();
153   }
154   return ret;
155 }
156
157 //
158 // Replace occurrences of special variables in the string.
159 //
160 #ifdef __ANDROID__
161 static std::string expandVars(const std::string &str) {
162 #ifdef __LP64__
163   return replaceAll(str, "$NATIVE_TESTS", "/data/nativetest64");
164 #else
165   return replaceAll(str, "$NATIVE_TESTS", "/data/nativetest");
166 #endif
167 }
168 #endif
169
170 class PerfProfdTest : public testing::Test {
171  protected:
172   virtual void SetUp() {
173     test_logger.Install();
174     create_dirs();
175   }
176
177   virtual void TearDown() {
178     android::base::SetLogger(android::base::StderrLogger);
179
180     // TODO: proper management of test files. For now, use old system() code.
181     for (const auto dir : { &dest_dir, &conf_dir }) {
182       std::string cmd("rm -rf ");
183       cmd += *dir;
184       int ret = system(cmd.c_str());
185       CHECK_EQ(0, ret);
186     }
187   }
188
189  protected:
190   //
191   // Check to see if the log messages emitted by the daemon
192   // match the expected result. By default we use a partial
193   // match, e.g. if we see the expected excerpt anywhere in the
194   // result, it's a match (for exact match, set exact to true)
195   //
196   void CompareLogMessages(const std::string& expected,
197                           const char* testpoint,
198                           bool exactMatch = false) {
199      std::string sqexp = squeezeWhite(expected, "expected");
200
201      // Strip out JIT errors.
202      std::regex jit_regex("E: Failed to open ELF file: [^ ]*ashmem/dalvik-jit-code-cache.*");
203      auto strip_jit = [&](const std::string& str) {
204        std::smatch jit_match;
205        return !std::regex_match(str, jit_match, jit_regex);
206      };
207      std::string sqact = squeezeWhite(test_logger.JoinTestLog(" ", strip_jit), "actual");
208
209      if (exactMatch) {
210        EXPECT_STREQ(sqexp.c_str(), sqact.c_str());
211      } else {
212        std::size_t foundpos = sqact.find(sqexp);
213        bool wasFound = true;
214        if (foundpos == std::string::npos) {
215          std::cerr << testpoint << ": expected result not found\n";
216          std::cerr << " Actual: \"" << sqact << "\"\n";
217          std::cerr << " Expected: \"" << sqexp << "\"\n";
218          wasFound = false;
219        }
220        EXPECT_TRUE(wasFound);
221      }
222   }
223
224   // test_dir is the directory containing the test executable and
225   // any files associated with the test (will be created by the harness).
226   std::string test_dir;
227
228   // dest_dir is a temporary directory that we're using as the destination directory.
229   // It is backed by temp_dir1.
230   std::string dest_dir;
231
232   // conf_dir is a temporary directory that we're using as the configuration directory.
233   // It is backed by temp_dir2.
234   std::string conf_dir;
235
236   TestLogHelper test_logger;
237
238  private:
239   void create_dirs() {
240     temp_dir1.reset(new TemporaryDir());
241     temp_dir2.reset(new TemporaryDir());
242     dest_dir = temp_dir1->path;
243     conf_dir = temp_dir2->path;
244     test_dir = android::base::Dirname(gExecutableRealpath);
245   }
246
247   std::unique_ptr<TemporaryDir> temp_dir1;
248   std::unique_ptr<TemporaryDir> temp_dir2;
249 };
250
251 ///
252 /// Helper class to kick off a run of the perfprofd daemon with a specific
253 /// config file.
254 ///
255 class PerfProfdRunner {
256  public:
257   explicit PerfProfdRunner(const std::string& config_dir)
258       : config_dir_(config_dir)
259   {
260     config_path_ = config_dir + "/" CONFIGFILE;
261   }
262
263   ~PerfProfdRunner()
264   {
265     remove_processed_file();
266   }
267
268   void addToConfig(const std::string &line)
269   {
270     config_text_ += line;
271     config_text_ += "\n";
272   }
273
274   void remove_semaphore_file()
275   {
276     std::string semaphore(config_dir_);
277     semaphore += "/" SEMAPHORE_FILENAME;
278     unlink(semaphore.c_str());
279   }
280
281   void create_semaphore_file()
282   {
283     std::string semaphore(config_dir_);
284     semaphore += "/" SEMAPHORE_FILENAME;
285     close(open(semaphore.c_str(), O_WRONLY|O_CREAT, 0600));
286   }
287
288   void write_processed_file(int start_seq, int end_seq)
289   {
290     std::string processed = config_dir_ + "/" PROCESSED_FILENAME;
291     FILE *fp = fopen(processed.c_str(), "w");
292     for (int i = start_seq; i < end_seq; i++) {
293       fprintf(fp, "%d\n", i);
294     }
295     fclose(fp);
296   }
297
298   void remove_processed_file()
299   {
300     std::string processed = config_dir_ + "/" PROCESSED_FILENAME;
301     unlink(processed.c_str());
302   }
303
304   struct LoggingConfig : public Config {
305     void Sleep(size_t seconds) override {
306       // Log sleep calls but don't sleep.
307       LOG(INFO) << "sleep " << seconds << " seconds";
308     }
309
310     bool IsProfilingEnabled() const override {
311       //
312       // Check for existence of semaphore file in config directory
313       //
314       if (access(config_directory.c_str(), F_OK) == -1) {
315         PLOG(WARNING) << "unable to open config directory " << config_directory;
316         return false;
317       }
318
319       // Check for existence of semaphore file
320       std::string semaphore_filepath = config_directory
321           + "/" + SEMAPHORE_FILENAME;
322       if (access(semaphore_filepath.c_str(), F_OK) == -1) {
323         return false;
324       }
325
326       return true;
327     }
328   };
329
330   int invoke()
331   {
332     static const char *argv[3] = { "perfprofd", "-c", "" };
333     argv[2] = config_path_.c_str();
334
335     writeConfigFile(config_path_, config_text_);
336
337     // execute daemon main
338     LoggingConfig config;
339     return perfprofd_main(3, (char **) argv, &config);
340   }
341
342  private:
343   std::string config_dir_;
344   std::string config_path_;
345   std::string config_text_;
346
347   void writeConfigFile(const std::string &config_path,
348                        const std::string &config_text)
349   {
350     FILE *fp = fopen(config_path.c_str(), "w");
351     ASSERT_TRUE(fp != nullptr);
352     fprintf(fp, "%s\n", config_text.c_str());
353     fclose(fp);
354   }
355 };
356
357 //......................................................................
358
359 static std::string encoded_file_path(const std::string& dest_dir,
360                                      int seq) {
361   return android::base::StringPrintf("%s/perf.data.encoded.%d",
362                                      dest_dir.c_str(), seq);
363 }
364
365 static void readEncodedProfile(const std::string& dest_dir,
366                                bool compressed,
367                                android::perfprofd::PerfprofdRecord& encodedProfile)
368 {
369   struct stat statb;
370   int perf_data_stat_result = stat(encoded_file_path(dest_dir, 0).c_str(), &statb);
371   ASSERT_NE(-1, perf_data_stat_result);
372
373   // read
374   std::string encoded;
375   encoded.resize(statb.st_size);
376   FILE *ifp = fopen(encoded_file_path(dest_dir, 0).c_str(), "r");
377   ASSERT_NE(nullptr, ifp);
378   size_t items_read = fread((void*) encoded.data(), statb.st_size, 1, ifp);
379   ASSERT_EQ(1, items_read);
380   fclose(ifp);
381
382   // uncompress
383   if (compressed && !encoded.empty()) {
384     z_stream stream;
385     stream.zalloc = Z_NULL;
386     stream.zfree = Z_NULL;
387     stream.opaque = Z_NULL;
388
389     {
390       constexpr int kWindowBits = 15;
391       constexpr int kGzipEncoding = 16;
392       int init_result = inflateInit2(&stream, kWindowBits | kGzipEncoding);
393       if (init_result != Z_OK) {
394         LOG(ERROR) << "Could not initialize libz stream " << init_result;
395         return;
396       }
397     }
398
399     std::string buf;
400     buf.reserve(2 * encoded.size());
401     stream.avail_in = encoded.size();
402     stream.next_in = reinterpret_cast<Bytef*>(const_cast<char*>(encoded.data()));
403
404     int result;
405     do {
406       uint8_t chunk[1024];
407       stream.next_out = static_cast<Bytef*>(chunk);
408       stream.avail_out = arraysize(chunk);
409
410       result = inflate(&stream, 0);
411       const size_t amount = arraysize(chunk) - stream.avail_out;
412       if (amount > 0) {
413         if (buf.capacity() - buf.size() < amount) {
414           buf.reserve(buf.capacity() + 64u * 1024u);
415           CHECK_LE(amount, buf.capacity() - buf.size());
416         }
417         size_t index = buf.size();
418         buf.resize(buf.size() + amount);
419         memcpy(reinterpret_cast<uint8_t*>(const_cast<char*>(buf.data())) + index, chunk, amount);
420       }
421     } while (result == Z_OK);
422     inflateEnd(&stream);
423     if (result != Z_STREAM_END) {
424       LOG(ERROR) << "Finished with not-Z_STREAM_END " << result;
425       return;
426     }
427     encoded = buf;
428   }
429
430   // decode
431   encodedProfile.ParseFromString(encoded);
432 }
433
434 #define RAW_RESULT(x) #x
435
436 TEST_F(PerfProfdTest, TestUtil)
437 {
438   EXPECT_EQ("", replaceAll("", "", ""));
439   EXPECT_EQ("zzbc", replaceAll("abc", "a", "zz"));
440   EXPECT_EQ("azzc", replaceAll("abc", "b", "zz"));
441   EXPECT_EQ("abzz", replaceAll("abc", "c", "zz"));
442   EXPECT_EQ("xxyyzz", replaceAll("abc", "abc", "xxyyzz"));
443 }
444
445 TEST_F(PerfProfdTest, MissingGMS)
446 {
447   //
448   // AWP requires cooperation between the daemon and the GMS core
449   // piece. If we're running on a device that has an old or damaged
450   // version of GMS core, then the config directory we're interested in
451   // may not be there. This test insures that the daemon does the
452   // right thing in this case.
453   //
454   PerfProfdRunner runner(conf_dir);
455   runner.addToConfig("only_debug_build=0");
456   runner.addToConfig("trace_config_read=0");
457   runner.addToConfig("config_directory=/does/not/exist");
458   runner.addToConfig("main_loop_iterations=1");
459   runner.addToConfig("use_fixed_seed=1");
460   runner.addToConfig("collection_interval=100");
461
462   // Kick off daemon
463   int daemon_main_return_code = runner.invoke();
464
465   // Check return code from daemon
466   EXPECT_EQ(0, daemon_main_return_code);
467
468   // Verify log contents
469   const std::string expected = RAW_RESULT(
470       I: sleep 90 seconds
471       W: unable to open config directory /does/not/exist: No such file or directory
472       I: profile collection skipped (missing config directory)
473                                           );
474
475   // check to make sure entire log matches
476   CompareLogMessages(expected, "MissingGMS");
477 }
478
479
480 TEST_F(PerfProfdTest, MissingOptInSemaphoreFile)
481 {
482   //
483   // Android device owners must opt in to "collect and report usage
484   // data" in order for us to be able to collect profiles. The opt-in
485   // check is performed in the GMS core component; if the check
486   // passes, then it creates a semaphore file for the daemon to pick
487   // up on.
488   //
489   PerfProfdRunner runner(conf_dir);
490   runner.addToConfig("only_debug_build=0");
491   std::string cfparam("config_directory="); cfparam += conf_dir;
492   runner.addToConfig(cfparam);
493   std::string ddparam("destination_directory="); ddparam += dest_dir;
494   runner.addToConfig(ddparam);
495   runner.addToConfig("main_loop_iterations=1");
496   runner.addToConfig("use_fixed_seed=1");
497   runner.addToConfig("collection_interval=100");
498
499   runner.remove_semaphore_file();
500
501   // Kick off daemon
502   int daemon_main_return_code = runner.invoke();
503
504   // Check return code from daemon
505   EXPECT_EQ(0, daemon_main_return_code);
506
507   // Verify log contents
508   const std::string expected = RAW_RESULT(
509       I: profile collection skipped (missing config directory)
510                                           );
511   // check to make sure log excerpt matches
512   CompareLogMessages(expected, "MissingOptInSemaphoreFile");
513 }
514
515 TEST_F(PerfProfdTest, MissingPerfExecutable)
516 {
517   //
518   // Perfprofd uses the 'simpleperf' tool to collect profiles
519   // (although this may conceivably change in the future). This test
520   // checks to make sure that if 'simpleperf' is not present we bail out
521   // from collecting profiles.
522   //
523   PerfProfdRunner runner(conf_dir);
524   runner.addToConfig("only_debug_build=0");
525   runner.addToConfig("trace_config_read=1");
526   std::string cfparam("config_directory="); cfparam += conf_dir;
527   runner.addToConfig(cfparam);
528   std::string ddparam("destination_directory="); ddparam += dest_dir;
529   runner.addToConfig(ddparam);
530   runner.addToConfig("main_loop_iterations=1");
531   runner.addToConfig("use_fixed_seed=1");
532   runner.addToConfig("collection_interval=100");
533   runner.addToConfig("perf_path=/does/not/exist");
534
535   // Create semaphore file
536   runner.create_semaphore_file();
537
538   // Kick off daemon
539   int daemon_main_return_code = runner.invoke();
540
541   // Check return code from daemon
542   EXPECT_EQ(0, daemon_main_return_code);
543
544   // expected log contents
545   const std::string expected = RAW_RESULT(
546       I: profile collection skipped (missing 'perf' executable)
547                                           );
548   // check to make sure log excerpt matches
549   CompareLogMessages(expected, "MissingPerfExecutable");
550 }
551
552 TEST_F(PerfProfdTest, BadPerfRun)
553 {
554   //
555   // Perf tools tend to be tightly coupled with a specific kernel
556   // version -- if things are out of sync perf could fail or
557   // crash. This test makes sure that we detect such a case and log
558   // the error.
559   //
560   PerfProfdRunner runner(conf_dir);
561   runner.addToConfig("only_debug_build=0");
562   std::string cfparam("config_directory="); cfparam += conf_dir;
563   runner.addToConfig(cfparam);
564   std::string ddparam("destination_directory="); ddparam += dest_dir;
565   runner.addToConfig(ddparam);
566   runner.addToConfig("main_loop_iterations=1");
567   runner.addToConfig("use_fixed_seed=1");
568   runner.addToConfig("collection_interval=100");
569 #ifdef __ANDROID__
570   runner.addToConfig("perf_path=/system/bin/false");
571 #else
572   runner.addToConfig("perf_path=/bin/false");
573 #endif
574
575   // Create semaphore file
576   runner.create_semaphore_file();
577
578   // Kick off daemon
579   int daemon_main_return_code = runner.invoke();
580
581   // Check return code from daemon
582   EXPECT_EQ(0, daemon_main_return_code);
583
584   // Verify log contents
585   const std::string expected = RAW_RESULT(
586       W: perf bad exit status 1
587       W: profile collection failed
588                                           );
589
590   // check to make sure log excerpt matches
591   CompareLogMessages(expected, "BadPerfRun");
592 }
593
594 TEST_F(PerfProfdTest, ConfigFileParsing)
595 {
596   //
597   // Gracefully handly malformed items in the config file
598   //
599   PerfProfdRunner runner(conf_dir);
600   runner.addToConfig("only_debug_build=0");
601   runner.addToConfig("main_loop_iterations=1");
602   runner.addToConfig("collection_interval=100");
603   runner.addToConfig("use_fixed_seed=1");
604   runner.addToConfig("destination_directory=/does/not/exist");
605
606   // assorted bad syntax
607   runner.addToConfig("collection_interval=0");
608   runner.addToConfig("collection_interval=-1");
609   runner.addToConfig("collection_interval=2");
610   runner.addToConfig("nonexistent_key=something");
611   runner.addToConfig("no_equals_stmt");
612
613   // Kick off daemon
614   int daemon_main_return_code = runner.invoke();
615
616   // Check return code from daemon
617   EXPECT_EQ(0, daemon_main_return_code);
618
619   // Verify log contents
620   const std::string expected = RAW_RESULT(
621       W: line 6: specified value 0 for 'collection_interval' outside permitted range [100 4294967295] (ignored)
622       W: line 7: malformed unsigned value (ignored)
623       W: line 8: specified value 2 for 'collection_interval' outside permitted range [100 4294967295] (ignored)
624       W: line 9: unknown option 'nonexistent_key' ignored
625       W: line 10: line malformed (no '=' found)
626                                           );
627
628   // check to make sure log excerpt matches
629   CompareLogMessages(expected, "ConfigFileParsing");
630 }
631
632 TEST_F(PerfProfdTest, ProfileCollectionAnnotations)
633 {
634   unsigned util1 = collect_cpu_utilization();
635   EXPECT_LE(util1, 100);
636   EXPECT_GE(util1, 0);
637
638   // NB: expectation is that when we run this test, the device will be
639   // completed booted, will be on charger, and will not have the camera
640   // active.
641   EXPECT_FALSE(get_booting());
642 #ifdef __ANDROID__
643   EXPECT_TRUE(get_charging());
644 #endif
645   EXPECT_FALSE(get_camera_active());
646 }
647
648 namespace {
649
650 template <typename Iterator>
651 size_t CountEvents(const quipper::PerfDataProto& proto) {
652   size_t count = 0;
653   for (Iterator it(proto); it != it.end(); ++it) {
654     count++;
655   }
656   return count;
657 }
658
659 size_t CountCommEvents(const quipper::PerfDataProto& proto) {
660   return CountEvents<CommEventIterator>(proto);
661 }
662 size_t CountMmapEvents(const quipper::PerfDataProto& proto) {
663   return CountEvents<MmapEventIterator>(proto);
664 }
665 size_t CountSampleEvents(const quipper::PerfDataProto& proto) {
666   return CountEvents<SampleEventIterator>(proto);
667 }
668 size_t CountForkEvents(const quipper::PerfDataProto& proto) {
669   return CountEvents<ForkEventIterator>(proto);
670 }
671 size_t CountExitEvents(const quipper::PerfDataProto& proto) {
672   return CountEvents<ExitEventIterator>(proto);
673 }
674
675 std::string CreateStats(const quipper::PerfDataProto& proto) {
676   std::ostringstream oss;
677   oss << "Mmap events: "   << CountMmapEvents(proto) << std::endl;
678   oss << "Sample events: " << CountSampleEvents(proto) << std::endl;
679   oss << "Comm events: "   << CountCommEvents(proto) << std::endl;
680   oss << "Fork events: "   << CountForkEvents(proto) << std::endl;
681   oss << "Exit events: "   << CountExitEvents(proto) << std::endl;
682   return oss.str();
683 }
684
685 std::string FormatSampleEvent(const quipper::PerfDataProto_SampleEvent& sample) {
686   std::ostringstream oss;
687   if (sample.has_pid()) {
688     oss << "pid=" << sample.pid();
689   }
690   if (sample.has_tid()) {
691     oss << " tid=" << sample.tid();
692   }
693   if (sample.has_ip()) {
694       oss << " ip=" << sample.ip();
695     }
696   if (sample.has_addr()) {
697     oss << " addr=" << sample.addr();
698   }
699   if (sample.callchain_size() > 0) {
700     oss << " callchain=";
701     for (uint64_t cc : sample.callchain()) {
702       oss << "->" << cc;
703     }
704   }
705   return oss.str();
706 }
707
708 }
709
710 struct BasicRunWithCannedPerf : PerfProfdTest {
711   void VerifyBasicCannedProfile(const android::perfprofd::PerfprofdRecord& encodedProfile) {
712     ASSERT_TRUE(encodedProfile.has_perf_data()) << test_logger.JoinTestLog(" ");
713     const quipper::PerfDataProto& perf_data = encodedProfile.perf_data();
714
715     // Expect 21108 events.
716     EXPECT_EQ(21108, perf_data.events_size()) << CreateStats(perf_data);
717
718     EXPECT_EQ(48,    CountMmapEvents(perf_data)) << CreateStats(perf_data);
719     EXPECT_EQ(19986, CountSampleEvents(perf_data)) << CreateStats(perf_data);
720     EXPECT_EQ(1033,  CountCommEvents(perf_data)) << CreateStats(perf_data);
721     EXPECT_EQ(15,    CountForkEvents(perf_data)) << CreateStats(perf_data);
722     EXPECT_EQ(26,    CountExitEvents(perf_data)) << CreateStats(perf_data);
723
724     if (HasNonfatalFailure()) {
725       FAIL();
726     }
727
728     {
729       MmapEventIterator mmap(perf_data);
730       constexpr std::pair<const char*, uint64_t> kMmapEvents[] = {
731           std::make_pair("[kernel.kallsyms]_text", 0),
732           std::make_pair("/system/lib/libc.so", 3067412480u),
733           std::make_pair("/system/vendor/lib/libdsutils.so", 3069911040u),
734           std::make_pair("/system/lib/libc.so", 3067191296u),
735           std::make_pair("/system/lib/libc++.so", 3069210624u),
736           std::make_pair("/data/dalvik-cache/arm/system@framework@boot.oat", 1900048384u),
737           std::make_pair("/system/lib/libjavacore.so", 2957135872u),
738           std::make_pair("/system/vendor/lib/libqmi_encdec.so", 3006644224u),
739           std::make_pair("/data/dalvik-cache/arm/system@framework@wifi-service.jar@classes.dex",
740                          3010351104u),
741                          std::make_pair("/system/lib/libart.so", 3024150528u),
742                          std::make_pair("/system/lib/libz.so", 3056410624u),
743                          std::make_pair("/system/lib/libicui18n.so", 3057610752u),
744       };
745       for (auto& pair : kMmapEvents) {
746         EXPECT_STREQ(pair.first, mmap->mmap_event().filename().c_str());
747         EXPECT_EQ(pair.second, mmap->mmap_event().start()) << pair.first;
748         ++mmap;
749       }
750     }
751
752     {
753       CommEventIterator comm(perf_data);
754       constexpr const char* kCommEvents[] = {
755           "init", "kthreadd", "ksoftirqd/0", "kworker/u:0H", "migration/0", "khelper",
756           "netns", "modem_notifier", "smd_channel_clo", "smsm_cb_wq", "rpm-smd", "kworker/u:1H",
757       };
758       for (auto str : kCommEvents) {
759         EXPECT_STREQ(str, comm->comm_event().comm().c_str());
760         ++comm;
761       }
762     }
763
764     {
765       SampleEventIterator samples(perf_data);
766       constexpr const char* kSampleEvents[] = {
767           "pid=0 tid=0 ip=3222720196",
768           "pid=0 tid=0 ip=3222910876",
769           "pid=0 tid=0 ip=3222910876",
770           "pid=0 tid=0 ip=3222910876",
771           "pid=0 tid=0 ip=3222910876",
772           "pid=0 tid=0 ip=3222910876",
773           "pid=0 tid=0 ip=3222910876",
774           "pid=3 tid=3 ip=3231975108",
775           "pid=5926 tid=5926 ip=3231964952",
776           "pid=5926 tid=5926 ip=3225342428",
777           "pid=5926 tid=5926 ip=3223841448",
778           "pid=5926 tid=5926 ip=3069807920",
779       };
780       for (auto str : kSampleEvents) {
781         EXPECT_STREQ(str, FormatSampleEvent(samples->sample_event()).c_str());
782         ++samples;
783       }
784
785       // Skip some samples.
786       for (size_t i = 0; i != 5000; ++i) {
787         ++samples;
788       }
789       constexpr const char* kSampleEvents2[] = {
790           "pid=5938 tid=5938 ip=3069630992",
791           "pid=5938 tid=5938 ip=3069626616",
792           "pid=5938 tid=5938 ip=3069626636",
793           "pid=5938 tid=5938 ip=3069637212",
794           "pid=5938 tid=5938 ip=3069637208",
795           "pid=5938 tid=5938 ip=3069637252",
796           "pid=5938 tid=5938 ip=3069346040",
797           "pid=5938 tid=5938 ip=3069637128",
798           "pid=5938 tid=5938 ip=3069626616",
799       };
800       for (auto str : kSampleEvents2) {
801         EXPECT_STREQ(str, FormatSampleEvent(samples->sample_event()).c_str());
802         ++samples;
803       }
804
805       // Skip some samples.
806       for (size_t i = 0; i != 5000; ++i) {
807         ++samples;
808       }
809       constexpr const char* kSampleEvents3[] = {
810           "pid=5938 tid=5938 ip=3069912036",
811           "pid=5938 tid=5938 ip=3069637260",
812           "pid=5938 tid=5938 ip=3069631024",
813           "pid=5938 tid=5938 ip=3069346064",
814           "pid=5938 tid=5938 ip=3069637356",
815           "pid=5938 tid=5938 ip=3069637144",
816           "pid=5938 tid=5938 ip=3069912036",
817           "pid=5938 tid=5938 ip=3069912036",
818           "pid=5938 tid=5938 ip=3069631244",
819       };
820       for (auto str : kSampleEvents3) {
821         EXPECT_STREQ(str, FormatSampleEvent(samples->sample_event()).c_str());
822         ++samples;
823       }
824     }
825   }
826 };
827
828 TEST_F(BasicRunWithCannedPerf, Basic)
829 {
830   //
831   // Verify the portion of the daemon that reads and encodes
832   // perf.data files. Here we run the encoder on a canned perf.data
833   // file and verify that the resulting protobuf contains what
834   // we think it should contain.
835   //
836   std::string input_perf_data(test_dir);
837   input_perf_data += "/canned.perf.data";
838
839   // Set up config to avoid these annotations (they are tested elsewhere)
840   ConfigReader config_reader;
841   config_reader.overrideUnsignedEntry("collect_cpu_utilization", 0);
842   config_reader.overrideUnsignedEntry("collect_charging_state", 0);
843   config_reader.overrideUnsignedEntry("collect_camera_active", 0);
844
845   // Disable compression.
846   config_reader.overrideUnsignedEntry("compress", 0);
847
848   PerfProfdRunner::LoggingConfig config;
849   config_reader.FillConfig(&config);
850
851   // Kick off encoder and check return code
852   PROFILE_RESULT result =
853       encode_to_proto(input_perf_data, encoded_file_path(dest_dir, 0).c_str(), config, 0, nullptr);
854   ASSERT_EQ(OK_PROFILE_COLLECTION, result) << test_logger.JoinTestLog(" ");
855
856   // Read and decode the resulting perf.data.encoded file
857   android::perfprofd::PerfprofdRecord encodedProfile;
858   readEncodedProfile(dest_dir, false, encodedProfile);
859
860   VerifyBasicCannedProfile(encodedProfile);
861 }
862
863 TEST_F(BasicRunWithCannedPerf, Compressed)
864 {
865   //
866   // Verify the portion of the daemon that reads and encodes
867   // perf.data files. Here we run the encoder on a canned perf.data
868   // file and verify that the resulting protobuf contains what
869   // we think it should contain.
870   //
871   std::string input_perf_data(test_dir);
872   input_perf_data += "/canned.perf.data";
873
874   // Set up config to avoid these annotations (they are tested elsewhere)
875   ConfigReader config_reader;
876   config_reader.overrideUnsignedEntry("collect_cpu_utilization", 0);
877   config_reader.overrideUnsignedEntry("collect_charging_state", 0);
878   config_reader.overrideUnsignedEntry("collect_camera_active", 0);
879
880   // Enable compression.
881   config_reader.overrideUnsignedEntry("compress", 1);
882
883   PerfProfdRunner::LoggingConfig config;
884   config_reader.FillConfig(&config);
885
886   // Kick off encoder and check return code
887   PROFILE_RESULT result =
888       encode_to_proto(input_perf_data, encoded_file_path(dest_dir, 0).c_str(), config, 0, nullptr);
889   ASSERT_EQ(OK_PROFILE_COLLECTION, result) << test_logger.JoinTestLog(" ");
890
891   // Read and decode the resulting perf.data.encoded file
892   android::perfprofd::PerfprofdRecord encodedProfile;
893   readEncodedProfile(dest_dir, true, encodedProfile);
894
895   VerifyBasicCannedProfile(encodedProfile);
896 }
897
898 TEST_F(BasicRunWithCannedPerf, DISABLED_WithSymbolizer)
899 {
900   //
901   // Verify the portion of the daemon that reads and encodes
902   // perf.data files. Here we run the encoder on a canned perf.data
903   // file and verify that the resulting protobuf contains what
904   // we think it should contain.
905   //
906   std::string input_perf_data(test_dir);
907   input_perf_data += "/canned.perf.data";
908
909   // Set up config to avoid these annotations (they are tested elsewhere)
910   ConfigReader config_reader;
911   config_reader.overrideUnsignedEntry("collect_cpu_utilization", 0);
912   config_reader.overrideUnsignedEntry("collect_charging_state", 0);
913   config_reader.overrideUnsignedEntry("collect_camera_active", 0);
914
915   // Disable compression.
916   config_reader.overrideUnsignedEntry("compress", 0);
917
918   PerfProfdRunner::LoggingConfig config;
919   config_reader.FillConfig(&config);
920
921   // Kick off encoder and check return code
922   struct TestSymbolizer : public perfprofd::Symbolizer {
923     std::string Decode(const std::string& dso, uint64_t address) override {
924       return dso + "@" + std::to_string(address);
925     }
926   };
927   TestSymbolizer test_symbolizer;
928   PROFILE_RESULT result =
929       encode_to_proto(input_perf_data,
930                       encoded_file_path(dest_dir, 0).c_str(),
931                       config,
932                       0,
933                       &test_symbolizer);
934   ASSERT_EQ(OK_PROFILE_COLLECTION, result);
935
936   // Read and decode the resulting perf.data.encoded file
937   android::perfprofd::PerfprofdRecord encodedProfile;
938   readEncodedProfile(dest_dir, false, encodedProfile);
939
940   VerifyBasicCannedProfile(encodedProfile);
941
942   // TODO: Re-add symbolization.
943 }
944
945 TEST_F(PerfProfdTest, CallchainRunWithCannedPerf)
946 {
947   // This test makes sure that the perf.data converter
948   // can handle call chains.
949   //
950   std::string input_perf_data(test_dir);
951   input_perf_data += "/callchain.canned.perf.data";
952
953   // Set up config to avoid these annotations (they are tested elsewhere)
954   ConfigReader config_reader;
955   config_reader.overrideUnsignedEntry("collect_cpu_utilization", 0);
956   config_reader.overrideUnsignedEntry("collect_charging_state", 0);
957   config_reader.overrideUnsignedEntry("collect_camera_active", 0);
958
959   // Disable compression.
960   config_reader.overrideUnsignedEntry("compress", 0);
961
962   PerfProfdRunner::LoggingConfig config;
963   config_reader.FillConfig(&config);
964
965   // Kick off encoder and check return code
966   PROFILE_RESULT result =
967       encode_to_proto(input_perf_data, encoded_file_path(dest_dir, 0).c_str(), config, 0, nullptr);
968   ASSERT_EQ(OK_PROFILE_COLLECTION, result);
969
970   // Read and decode the resulting perf.data.encoded file
971   android::perfprofd::PerfprofdRecord encodedProfile;
972   readEncodedProfile(dest_dir, false, encodedProfile);
973
974
975   ASSERT_TRUE(encodedProfile.has_perf_data());
976   const quipper::PerfDataProto& perf_data = encodedProfile.perf_data();
977
978   // Expect 21108 events.
979   EXPECT_EQ(2224, perf_data.events_size()) << CreateStats(perf_data);
980
981   {
982       SampleEventIterator samples(perf_data);
983       constexpr const char* kSampleEvents[] = {
984           "0: pid=6225 tid=6225 ip=18446743798834668032 callchain=->18446744073709551488->"
985               "18446743798834668032->18446743798834782596->18446743798834784624->"
986               "18446743798835055136->18446743798834788016->18446743798834789192->"
987               "18446743798834789512->18446743798834790216->18446743798833756776",
988           "1: pid=6225 tid=6225 ip=18446743798835685700 callchain=->18446744073709551488->"
989               "18446743798835685700->18446743798835688704->18446743798835650964->"
990               "18446743798834612104->18446743798834612276->18446743798835055528->"
991               "18446743798834788016->18446743798834789192->18446743798834789512->"
992               "18446743798834790216->18446743798833756776",
993           "2: pid=6225 tid=6225 ip=18446743798835055804 callchain=->18446744073709551488->"
994               "18446743798835055804->18446743798834788016->18446743798834789192->"
995               "18446743798834789512->18446743798834790216->18446743798833756776",
996           "3: pid=6225 tid=6225 ip=18446743798835991212 callchain=->18446744073709551488->"
997               "18446743798835991212->18446743798834491060->18446743798834675572->"
998               "18446743798834676516->18446743798834612172->18446743798834612276->"
999               "18446743798835056664->18446743798834788016->18446743798834789192->"
1000               "18446743798834789512->18446743798834790216->18446743798833756776",
1001           "4: pid=6225 tid=6225 ip=18446743798844881108 callchain=->18446744073709551488->"
1002               "18446743798844881108->18446743798834836140->18446743798834846384->"
1003               "18446743798834491100->18446743798834675572->18446743798834676516->"
1004               "18446743798834612172->18446743798834612276->18446743798835056784->"
1005               "18446743798834788016->18446743798834789192->18446743798834789512->"
1006               "18446743798834790216->18446743798833756776",
1007       };
1008       size_t cmp_index = 0;
1009       for (size_t index = 0; samples != samples.end(); ++samples, ++index) {
1010         if (samples->sample_event().callchain_size() > 0) {
1011           std::ostringstream oss;
1012           oss << index << ": " << FormatSampleEvent(samples->sample_event());
1013           EXPECT_STREQ(kSampleEvents[cmp_index], oss.str().c_str());
1014           cmp_index++;
1015           if (cmp_index == arraysize(kSampleEvents)) {
1016             break;
1017           }
1018         }
1019       }
1020   }
1021 }
1022
1023 #ifdef __ANDROID__
1024
1025 TEST_F(PerfProfdTest, BasicRunWithLivePerf)
1026 {
1027   //
1028   // Basic test to exercise the main loop of the daemon. It includes
1029   // a live 'perf' run
1030   //
1031   PerfProfdRunner runner(conf_dir);
1032   runner.addToConfig("only_debug_build=0");
1033   std::string ddparam("destination_directory="); ddparam += dest_dir;
1034   runner.addToConfig(ddparam);
1035   std::string cfparam("config_directory="); cfparam += conf_dir;
1036   runner.addToConfig(cfparam);
1037   runner.addToConfig("main_loop_iterations=1");
1038   runner.addToConfig("use_fixed_seed=12345678");
1039   runner.addToConfig("max_unprocessed_profiles=100");
1040   runner.addToConfig("collection_interval=9999");
1041   runner.addToConfig("sample_duration=2");
1042   // Avoid the symbolizer for spurious messages.
1043   runner.addToConfig("use_elf_symbolizer=0");
1044
1045   // Disable compression.
1046   runner.addToConfig("compress=0");
1047
1048   // Create semaphore file
1049   runner.create_semaphore_file();
1050
1051   // Kick off daemon
1052   int daemon_main_return_code = runner.invoke();
1053
1054   // Check return code from daemon
1055   ASSERT_EQ(0, daemon_main_return_code);
1056
1057   // Read and decode the resulting perf.data.encoded file
1058   android::perfprofd::PerfprofdRecord encodedProfile;
1059   readEncodedProfile(dest_dir, false, encodedProfile);
1060
1061   // Examine what we get back. Since it's a live profile, we can't
1062   // really do much in terms of verifying the contents.
1063   EXPECT_LT(0, encodedProfile.perf_data().events_size());
1064
1065   // Verify log contents
1066   const std::string expected = std::string(
1067       "I: starting Android Wide Profiling daemon ") +
1068       "I: config file path set to " + conf_dir + "/perfprofd.conf " +
1069       RAW_RESULT(
1070       I: random seed set to 12345678
1071       I: sleep 674 seconds
1072       I: initiating profile collection
1073       I: sleep 2 seconds
1074       I: profile collection complete
1075       I: sleep 9325 seconds
1076       I: finishing Android Wide Profiling daemon
1077                                           );
1078   // check to make sure log excerpt matches
1079   CompareLogMessages(expandVars(expected), "BasicRunWithLivePerf", true);
1080 }
1081
1082 TEST_F(PerfProfdTest, MultipleRunWithLivePerf)
1083 {
1084   //
1085   // Basic test to exercise the main loop of the daemon. It includes
1086   // a live 'perf' run
1087   //
1088   PerfProfdRunner runner(conf_dir);
1089   runner.addToConfig("only_debug_build=0");
1090   std::string ddparam("destination_directory="); ddparam += dest_dir;
1091   runner.addToConfig(ddparam);
1092   std::string cfparam("config_directory="); cfparam += conf_dir;
1093   runner.addToConfig(cfparam);
1094   runner.addToConfig("main_loop_iterations=3");
1095   runner.addToConfig("use_fixed_seed=12345678");
1096   runner.addToConfig("collection_interval=9999");
1097   runner.addToConfig("sample_duration=2");
1098   // Avoid the symbolizer for spurious messages.
1099   runner.addToConfig("use_elf_symbolizer=0");
1100
1101   // Disable compression.
1102   runner.addToConfig("compress=0");
1103
1104   runner.write_processed_file(1, 2);
1105
1106   // Create semaphore file
1107   runner.create_semaphore_file();
1108
1109   // Kick off daemon
1110   int daemon_main_return_code = runner.invoke();
1111
1112   // Check return code from daemon
1113   ASSERT_EQ(0, daemon_main_return_code);
1114
1115   // Read and decode the resulting perf.data.encoded file
1116   android::perfprofd::PerfprofdRecord encodedProfile;
1117   readEncodedProfile(dest_dir, false, encodedProfile);
1118
1119   // Examine what we get back. Since it's a live profile, we can't
1120   // really do much in terms of verifying the contents.
1121   EXPECT_LT(0, encodedProfile.perf_data().events_size());
1122
1123   // Examine that encoded.1 file is removed while encoded.{0|2} exists.
1124   EXPECT_EQ(0, access(encoded_file_path(dest_dir, 0).c_str(), F_OK));
1125   EXPECT_NE(0, access(encoded_file_path(dest_dir, 1).c_str(), F_OK));
1126   EXPECT_EQ(0, access(encoded_file_path(dest_dir, 2).c_str(), F_OK));
1127
1128   // Verify log contents
1129   const std::string expected = std::string(
1130       "I: starting Android Wide Profiling daemon ") +
1131       "I: config file path set to " + conf_dir + "/perfprofd.conf " +
1132       RAW_RESULT(
1133       I: random seed set to 12345678
1134       I: sleep 674 seconds
1135       I: initiating profile collection
1136       I: sleep 2 seconds
1137       I: profile collection complete
1138       I: sleep 9325 seconds
1139       I: sleep 4974 seconds
1140       I: initiating profile collection
1141       I: sleep 2 seconds
1142       I: profile collection complete
1143       I: sleep 5025 seconds
1144       I: sleep 501 seconds
1145       I: initiating profile collection
1146       I: sleep 2 seconds
1147       I: profile collection complete
1148       I: sleep 9498 seconds
1149       I: finishing Android Wide Profiling daemon
1150                                           );
1151   // check to make sure log excerpt matches
1152   CompareLogMessages(expandVars(expected), "BasicRunWithLivePerf", true);
1153 }
1154
1155 TEST_F(PerfProfdTest, CallChainRunWithLivePerf)
1156 {
1157   //
1158   // Collect a callchain profile, so as to exercise the code in
1159   // perf_data post-processing that digests callchains.
1160   //
1161   PerfProfdRunner runner(conf_dir);
1162   std::string ddparam("destination_directory="); ddparam += dest_dir;
1163   runner.addToConfig(ddparam);
1164   std::string cfparam("config_directory="); cfparam += conf_dir;
1165   runner.addToConfig(cfparam);
1166   runner.addToConfig("main_loop_iterations=1");
1167   runner.addToConfig("use_fixed_seed=12345678");
1168   runner.addToConfig("max_unprocessed_profiles=100");
1169   runner.addToConfig("collection_interval=9999");
1170   runner.addToConfig("stack_profile=1");
1171   runner.addToConfig("sample_duration=2");
1172   // Avoid the symbolizer for spurious messages.
1173   runner.addToConfig("use_elf_symbolizer=0");
1174
1175   // Disable compression.
1176   runner.addToConfig("compress=0");
1177
1178   // Create semaphore file
1179   runner.create_semaphore_file();
1180
1181   // Kick off daemon
1182   int daemon_main_return_code = runner.invoke();
1183
1184   // Check return code from daemon
1185   ASSERT_EQ(0, daemon_main_return_code);
1186
1187   // Read and decode the resulting perf.data.encoded file
1188   android::perfprofd::PerfprofdRecord encodedProfile;
1189   readEncodedProfile(dest_dir, false, encodedProfile);
1190
1191   // Examine what we get back. Since it's a live profile, we can't
1192   // really do much in terms of verifying the contents.
1193   EXPECT_LT(0, encodedProfile.perf_data().events_size());
1194
1195   // Verify log contents
1196   const std::string expected = std::string(
1197       "I: starting Android Wide Profiling daemon ") +
1198       "I: config file path set to " + conf_dir + "/perfprofd.conf " +
1199       RAW_RESULT(
1200       I: random seed set to 12345678
1201       I: sleep 674 seconds
1202       I: initiating profile collection
1203       I: sleep 2 seconds
1204       I: profile collection complete
1205       I: sleep 9325 seconds
1206       I: finishing Android Wide Profiling daemon
1207                                           );
1208   // check to make sure log excerpt matches
1209   CompareLogMessages(expandVars(expected), "CallChainRunWithLivePerf", true);
1210
1211   // Check that we have at least one SampleEvent with a callchain.
1212   SampleEventIterator samples(encodedProfile.perf_data());
1213   bool found_callchain = false;
1214   while (!found_callchain && samples != samples.end()) {
1215     found_callchain = samples->sample_event().callchain_size() > 0;
1216   }
1217   EXPECT_TRUE(found_callchain) << CreateStats(encodedProfile.perf_data());
1218 }
1219
1220 #endif
1221
1222 int main(int argc, char **argv) {
1223   // Always log to cerr, so that device failures are visible.
1224   android::base::SetLogger(android::base::StderrLogger);
1225
1226   CHECK(android::base::Realpath(argv[0], &gExecutableRealpath));
1227
1228   // switch to / before starting testing (perfprofd
1229   // should be location-independent)
1230   chdir("/");
1231   testing::InitGoogleTest(&argc, argv);
1232   return RUN_ALL_TESTS();
1233 }