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