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 <memory>
  21 #include <mutex>
  22 #include <regex>
  23 #include <string>
  24
  25 #include <fcntl.h>
  26 #include <stdio.h>
  27 #include <libgen.h>
  28 #include <sys/types.h>
  29 #include <sys/stat.h>
  30
  31 #include <android-base/file.h>
  32 #include <android-base/logging.h>
  33 #include <android-base/macros.h>
  34 #include <android-base/properties.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 "symbolizer.h"
  45
  46 #include "perf_profile.pb.h"
  47 #include "google/protobuf/text_format.h"
  48
  49 //
  50 // Set to argv[0] on startup
  51 //
  52 static std::string gExecutableRealpath;
  53
  54 namespace {
  55
  56 using android::base::LogId;
  57 using android::base::LogSeverity;
  58
  59 class TestLogHelper {
  60  public:
  61   void Install() {
  62     using namespace std::placeholders;
  63     android::base::SetLogger(
  64         std::bind(&TestLogHelper::TestLogFunction, this, _1, _2, _3, _4, _5, _6));
  65   }
  66
  67   std::string JoinTestLog(const char* delimiter) {
  68     std::unique_lock<std::mutex> ul(lock_);
  69     return android::base::Join(test_log_messages_, delimiter);
  70   }
  71
  72  private:
  73   void TestLogFunction(LogId log_id ATTRIBUTE_UNUSED,
  74                        LogSeverity severity,
  75                        const char* tag,
  76                        const char* file ATTRIBUTE_UNUSED,
  77                        unsigned int line ATTRIBUTE_UNUSED,
  78                        const char* message) {
  79     std::unique_lock<std::mutex> ul(lock_);
  80     constexpr char log_characters[] = "VDIWEFF";
  81     char severity_char = log_characters[severity];
  82     test_log_messages_.push_back(android::base::StringPrintf("%c: %s", severity_char, message));
  83   }
  84
  85  private:
  86   std::mutex lock_;
  87
  88   std::vector<std::string> test_log_messages_;
  89 };
  90
  91 }  // namespace
  92
  93 // Path to perf executable on device
  94 #define PERFPATH "/system/bin/perf"
  95
  96 // Temporary config file that we will emit for the daemon to read
  97 #define CONFIGFILE "perfprofd.conf"
  98
  99 static bool bothWhiteSpace(char lhs, char rhs)
 100 {
 101   return (std::isspace(lhs) && std::isspace(rhs));
 102 }
 103
 104 //
 105 // Squeeze out repeated whitespace from expected/actual logs.
 106 //
 107 static std::string squeezeWhite(const std::string &str,
 108                                 const char *tag,
 109                                 bool dump=false)
 110 {
 111   if (dump) { fprintf(stderr, "raw %s is %s\n", tag, str.c_str()); }
 112   std::string result(str);
 113   std::replace(result.begin(), result.end(), '\n', ' ');
 114   auto new_end = std::unique(result.begin(), result.end(), bothWhiteSpace);
 115   result.erase(new_end, result.end());
 116   while (result.begin() != result.end() && std::isspace(*result.rbegin())) {
 117     result.pop_back();
 118   }
 119   if (dump) { fprintf(stderr, "squeezed %s is %s\n", tag, result.c_str()); }
 120   return result;
 121 }
 122
 123 //
 124 // Replace all occurrences of a string with another string.
 125 //
 126 static std::string replaceAll(const std::string &str,
 127                               const std::string &from,
 128                               const std::string &to)
 129 {
 130   std::string ret = "";
 131   size_t pos = 0;
 132   while (pos < str.size()) {
 133     size_t found = str.find(from, pos);
 134     if (found == std::string::npos) {
 135       ret += str.substr(pos);
 136       break;
 137     }
 138     ret += str.substr(pos, found - pos) + to;
 139     pos = found + from.size();
 140   }
 141   return ret;
 142 }
 143
 144 //
 145 // Replace occurrences of special variables in the string.
 146 //
 147 static std::string expandVars(const std::string &str) {
 148 #ifdef __LP64__
 149   return replaceAll(str, "$NATIVE_TESTS", "/data/nativetest64");
 150 #else
 151   return replaceAll(str, "$NATIVE_TESTS", "/data/nativetest");
 152 #endif
 153 }
 154
 155 class PerfProfdTest : public testing::Test {
 156  protected:
 157   virtual void SetUp() {
 158     test_logger.Install();
 159     create_dirs();
 160   }
 161
 162   virtual void TearDown() {
 163     android::base::SetLogger(android::base::StderrLogger);
 164
 165     // TODO: proper management of test files. For now, use old system() code.
 166     for (const auto dir : { &dest_dir, &conf_dir }) {
 167       std::string cmd("rm -rf ");
 168       cmd += *dir;
 169       int ret = system(cmd.c_str());
 170       CHECK_EQ(0, ret);
 171     }
 172   }
 173
 174  protected:
 175   //
 176   // Check to see if the log messages emitted by the daemon
 177   // match the expected result. By default we use a partial
 178   // match, e.g. if we see the expected excerpt anywhere in the
 179   // result, it's a match (for exact match, set exact to true)
 180   //
 181   void CompareLogMessages(const std::string& expected,
 182                           const char* testpoint,
 183                           bool exactMatch = false) {
 184      std::string sqexp = squeezeWhite(expected, "expected");
 185      std::string sqact = squeezeWhite(test_logger.JoinTestLog(" "), "actual");
 186      if (exactMatch) {
 187        EXPECT_STREQ(sqexp.c_str(), sqact.c_str());
 188      } else {
 189        std::size_t foundpos = sqact.find(sqexp);
 190        bool wasFound = true;
 191        if (foundpos == std::string::npos) {
 192          std::cerr << testpoint << ": expected result not found\n";
 193          std::cerr << " Actual: \"" << sqact << "\"\n";
 194          std::cerr << " Expected: \"" << sqexp << "\"\n";
 195          wasFound = false;
 196        }
 197        EXPECT_TRUE(wasFound);
 198      }
 199   }
 200
 201   // test_dir is the directory containing the test executable and
 202   // any files associated with the test (will be created by the harness).
 203   std::string test_dir;
 204
 205   // dest_dir is a temporary directory that we're using as the destination directory.
 206   // It is backed by temp_dir1.
 207   std::string dest_dir;
 208
 209   // conf_dir is a temporary directory that we're using as the configuration directory.
 210   // It is backed by temp_dir2.
 211   std::string conf_dir;
 212
 213   TestLogHelper test_logger;
 214
 215  private:
 216   void create_dirs() {
 217     temp_dir1.reset(new TemporaryDir());
 218     temp_dir2.reset(new TemporaryDir());
 219     dest_dir = temp_dir1->path;
 220     conf_dir = temp_dir2->path;
 221     test_dir = android::base::Dirname(gExecutableRealpath);
 222   }
 223
 224   std::unique_ptr<TemporaryDir> temp_dir1;
 225   std::unique_ptr<TemporaryDir> temp_dir2;
 226 };
 227
 228 ///
 229 /// Helper class to kick off a run of the perfprofd daemon with a specific
 230 /// config file.
 231 ///
 232 class PerfProfdRunner {
 233  public:
 234   explicit PerfProfdRunner(const std::string& config_dir)
 235       : config_dir_(config_dir)
 236   {
 237     config_path_ = config_dir + "/" CONFIGFILE;
 238   }
 239
 240   ~PerfProfdRunner()
 241   {
 242     remove_processed_file();
 243   }
 244
 245   void addToConfig(const std::string &line)
 246   {
 247     config_text_ += line;
 248     config_text_ += "\n";
 249   }
 250
 251   void remove_semaphore_file()
 252   {
 253     std::string semaphore(config_dir_);
 254     semaphore += "/" SEMAPHORE_FILENAME;
 255     unlink(semaphore.c_str());
 256   }
 257
 258   void create_semaphore_file()
 259   {
 260     std::string semaphore(config_dir_);
 261     semaphore += "/" SEMAPHORE_FILENAME;
 262     close(open(semaphore.c_str(), O_WRONLY|O_CREAT, 0600));
 263   }
 264
 265   void write_processed_file(int start_seq, int end_seq)
 266   {
 267     std::string processed = config_dir_ + "/" PROCESSED_FILENAME;
 268     FILE *fp = fopen(processed.c_str(), "w");
 269     for (int i = start_seq; i < end_seq; i++) {
 270       fprintf(fp, "%d\n", i);
 271     }
 272     fclose(fp);
 273   }
 274
 275   void remove_processed_file()
 276   {
 277     std::string processed = config_dir_ + "/" PROCESSED_FILENAME;
 278     unlink(processed.c_str());
 279   }
 280
 281   struct LoggingConfig : public Config {
 282     void Sleep(size_t seconds) override {
 283       // Log sleep calls but don't sleep.
 284       LOG(INFO) << "sleep " << seconds << " seconds";
 285     }
 286
 287     bool IsProfilingEnabled() const override {
 288       //
 289       // Check for existence of semaphore file in config directory
 290       //
 291       if (access(config_directory.c_str(), F_OK) == -1) {
 292         PLOG(WARNING) << "unable to open config directory " << config_directory;
 293         return false;
 294       }
 295
 296       // Check for existence of semaphore file
 297       std::string semaphore_filepath = config_directory
 298           + "/" + SEMAPHORE_FILENAME;
 299       if (access(semaphore_filepath.c_str(), F_OK) == -1) {
 300         return false;
 301       }
 302
 303       return true;
 304     }
 305   };
 306
 307   int invoke()
 308   {
 309     static const char *argv[3] = { "perfprofd", "-c", "" };
 310     argv[2] = config_path_.c_str();
 311
 312     writeConfigFile(config_path_, config_text_);
 313
 314     // execute daemon main
 315     LoggingConfig config;
 316     return perfprofd_main(3, (char **) argv, &config);
 317   }
 318
 319  private:
 320   std::string config_dir_;
 321   std::string config_path_;
 322   std::string config_text_;
 323
 324   void writeConfigFile(const std::string &config_path,
 325                        const std::string &config_text)
 326   {
 327     FILE *fp = fopen(config_path.c_str(), "w");
 328     ASSERT_TRUE(fp != nullptr);
 329     fprintf(fp, "%s\n", config_text.c_str());
 330     fclose(fp);
 331   }
 332 };
 333
 334 //......................................................................
 335
 336 static std::string encoded_file_path(const std::string& dest_dir,
 337                                      int seq) {
 338   return android::base::StringPrintf("%s/perf.data.encoded.%d",
 339                                      dest_dir.c_str(), seq);
 340 }
 341
 342 static void readEncodedProfile(const std::string& dest_dir,
 343                                const char *testpoint,
 344                                wireless_android_play_playlog::AndroidPerfProfile &encodedProfile)
 345 {
 346   struct stat statb;
 347   int perf_data_stat_result = stat(encoded_file_path(dest_dir, 0).c_str(), &statb);
 348   ASSERT_NE(-1, perf_data_stat_result);
 349
 350   // read
 351   std::string encoded;
 352   encoded.resize(statb.st_size);
 353   FILE *ifp = fopen(encoded_file_path(dest_dir, 0).c_str(), "r");
 354   ASSERT_NE(nullptr, ifp);
 355   size_t items_read = fread((void*) encoded.data(), statb.st_size, 1, ifp);
 356   ASSERT_EQ(1, items_read);
 357   fclose(ifp);
 358
 359   // decode
 360   encodedProfile.ParseFromString(encoded);
 361 }
 362
 363 static std::string encodedLoadModuleToString(const wireless_android_play_playlog::LoadModule &lm)
 364 {
 365   std::stringstream ss;
 366   ss << "name: \"" << lm.name() << "\"\n";
 367   if (lm.build_id() != "") {
 368     ss << "build_id: \"" << lm.build_id() << "\"\n";
 369   }
 370   for (const auto& symbol : lm.symbol()) {
 371     ss << "symbol: \"" << symbol << "\"\n";
 372   }
 373   return ss.str();
 374 }
 375
 376 static std::string encodedModuleSamplesToString(const wireless_android_play_playlog::LoadModuleSamples &mod)
 377 {
 378   std::stringstream ss;
 379
 380   ss << "load_module_id: " << mod.load_module_id() << "\n";
 381   for (size_t k = 0; k < mod.address_samples_size(); k++) {
 382     const auto &sample = mod.address_samples(k);
 383     ss << "  address_samples {\n";
 384     for (size_t l = 0; l < mod.address_samples(k).address_size();
 385          l++) {
 386       auto address = mod.address_samples(k).address(l);
 387       ss << "    address: " << address << "\n";
 388     }
 389     ss << "    count: " << sample.count() << "\n";
 390     ss << "  }\n";
 391   }
 392   return ss.str();
 393 }
 394
 395 #define RAW_RESULT(x) #x
 396
 397 TEST_F(PerfProfdTest, TestUtil)
 398 {
 399   EXPECT_EQ("", replaceAll("", "", ""));
 400   EXPECT_EQ("zzbc", replaceAll("abc", "a", "zz"));
 401   EXPECT_EQ("azzc", replaceAll("abc", "b", "zz"));
 402   EXPECT_EQ("abzz", replaceAll("abc", "c", "zz"));
 403   EXPECT_EQ("xxyyzz", replaceAll("abc", "abc", "xxyyzz"));
 404 }
 405
 406 TEST_F(PerfProfdTest, MissingGMS)
 407 {
 408   //
 409   // AWP requires cooperation between the daemon and the GMS core
 410   // piece. If we're running on a device that has an old or damaged
 411   // version of GMS core, then the config directory we're interested in
 412   // may not be there. This test insures that the daemon does the
 413   // right thing in this case.
 414   //
 415   PerfProfdRunner runner(conf_dir);
 416   runner.addToConfig("only_debug_build=0");
 417   runner.addToConfig("trace_config_read=0");
 418   runner.addToConfig("config_directory=/does/not/exist");
 419   runner.addToConfig("main_loop_iterations=1");
 420   runner.addToConfig("use_fixed_seed=1");
 421   runner.addToConfig("collection_interval=100");
 422
 423   // Kick off daemon
 424   int daemon_main_return_code = runner.invoke();
 425
 426   // Check return code from daemon
 427   EXPECT_EQ(0, daemon_main_return_code);
 428
 429   // Verify log contents
 430   const std::string expected = RAW_RESULT(
 431       I: sleep 90 seconds
 432       W: unable to open config directory /does/not/exist: No such file or directory
 433       I: profile collection skipped (missing config directory)
 434                                           );
 435
 436   // check to make sure entire log matches
 437   CompareLogMessages(expected, "MissingGMS");
 438 }
 439
 440
 441 TEST_F(PerfProfdTest, MissingOptInSemaphoreFile)
 442 {
 443   //
 444   // Android device owners must opt in to "collect and report usage
 445   // data" in order for us to be able to collect profiles. The opt-in
 446   // check is performed in the GMS core component; if the check
 447   // passes, then it creates a semaphore file for the daemon to pick
 448   // up on.
 449   //
 450   PerfProfdRunner runner(conf_dir);
 451   runner.addToConfig("only_debug_build=0");
 452   std::string cfparam("config_directory="); cfparam += conf_dir;
 453   runner.addToConfig(cfparam);
 454   std::string ddparam("destination_directory="); ddparam += dest_dir;
 455   runner.addToConfig(ddparam);
 456   runner.addToConfig("main_loop_iterations=1");
 457   runner.addToConfig("use_fixed_seed=1");
 458   runner.addToConfig("collection_interval=100");
 459
 460   runner.remove_semaphore_file();
 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: profile collection skipped (missing config directory)
 471                                           );
 472   // check to make sure log excerpt matches
 473   CompareLogMessages(expected, "MissingOptInSemaphoreFile");
 474 }
 475
 476 TEST_F(PerfProfdTest, MissingPerfExecutable)
 477 {
 478   //
 479   // Perfprofd uses the 'simpleperf' tool to collect profiles
 480   // (although this may conceivably change in the future). This test
 481   // checks to make sure that if 'simpleperf' is not present we bail out
 482   // from collecting profiles.
 483   //
 484   PerfProfdRunner runner(conf_dir);
 485   runner.addToConfig("only_debug_build=0");
 486   runner.addToConfig("trace_config_read=1");
 487   std::string cfparam("config_directory="); cfparam += conf_dir;
 488   runner.addToConfig(cfparam);
 489   std::string ddparam("destination_directory="); ddparam += dest_dir;
 490   runner.addToConfig(ddparam);
 491   runner.addToConfig("main_loop_iterations=1");
 492   runner.addToConfig("use_fixed_seed=1");
 493   runner.addToConfig("collection_interval=100");
 494   runner.addToConfig("perf_path=/does/not/exist");
 495
 496   // Create semaphore file
 497   runner.create_semaphore_file();
 498
 499   // Kick off daemon
 500   int daemon_main_return_code = runner.invoke();
 501
 502   // Check return code from daemon
 503   EXPECT_EQ(0, daemon_main_return_code);
 504
 505   // expected log contents
 506   const std::string expected = RAW_RESULT(
 507       I: profile collection skipped (missing 'perf' executable)
 508                                           );
 509   // check to make sure log excerpt matches
 510   CompareLogMessages(expected, "MissingPerfExecutable");
 511 }
 512
 513 TEST_F(PerfProfdTest, BadPerfRun)
 514 {
 515   //
 516   // Perf tools tend to be tightly coupled with a specific kernel
 517   // version -- if things are out of sync perf could fail or
 518   // crash. This test makes sure that we detect such a case and log
 519   // the error.
 520   //
 521   PerfProfdRunner runner(conf_dir);
 522   runner.addToConfig("only_debug_build=0");
 523   std::string cfparam("config_directory="); cfparam += conf_dir;
 524   runner.addToConfig(cfparam);
 525   std::string ddparam("destination_directory="); ddparam += dest_dir;
 526   runner.addToConfig(ddparam);
 527   runner.addToConfig("main_loop_iterations=1");
 528   runner.addToConfig("use_fixed_seed=1");
 529   runner.addToConfig("collection_interval=100");
 530   runner.addToConfig("perf_path=/system/bin/false");
 531
 532   // Create semaphore file
 533   runner.create_semaphore_file();
 534
 535   // Kick off daemon
 536   int daemon_main_return_code = runner.invoke();
 537
 538   // Check return code from daemon
 539   EXPECT_EQ(0, daemon_main_return_code);
 540
 541   // Verify log contents
 542   const std::string expected = RAW_RESULT(
 543       W: perf bad exit status 1
 544       W: profile collection failed
 545                                           );
 546
 547   // check to make sure log excerpt matches
 548   CompareLogMessages(expected, "BadPerfRun");
 549 }
 550
 551 TEST_F(PerfProfdTest, ConfigFileParsing)
 552 {
 553   //
 554   // Gracefully handly malformed items in the config file
 555   //
 556   PerfProfdRunner runner(conf_dir);
 557   runner.addToConfig("only_debug_build=0");
 558   runner.addToConfig("main_loop_iterations=1");
 559   runner.addToConfig("collection_interval=100");
 560   runner.addToConfig("use_fixed_seed=1");
 561   runner.addToConfig("destination_directory=/does/not/exist");
 562
 563   // assorted bad syntax
 564   runner.addToConfig("collection_interval=0");
 565   runner.addToConfig("collection_interval=-1");
 566   runner.addToConfig("collection_interval=2");
 567   runner.addToConfig("nonexistent_key=something");
 568   runner.addToConfig("no_equals_stmt");
 569
 570   // Kick off daemon
 571   int daemon_main_return_code = runner.invoke();
 572
 573   // Check return code from daemon
 574   EXPECT_EQ(0, daemon_main_return_code);
 575
 576   // Verify log contents
 577   const std::string expected = RAW_RESULT(
 578       W: line 6: specified value 0 for 'collection_interval' outside permitted range [100 4294967295] (ignored)
 579       W: line 7: malformed unsigned value (ignored)
 580       W: line 8: specified value 2 for 'collection_interval' outside permitted range [100 4294967295] (ignored)
 581       W: line 9: unknown option 'nonexistent_key' ignored
 582       W: line 10: line malformed (no '=' found)
 583                                           );
 584
 585   // check to make sure log excerpt matches
 586   CompareLogMessages(expected, "ConfigFileParsing");
 587 }
 588
 589 TEST_F(PerfProfdTest, ProfileCollectionAnnotations)
 590 {
 591   unsigned util1 = collect_cpu_utilization();
 592   EXPECT_LE(util1, 100);
 593   EXPECT_GE(util1, 0);
 594
 595   // NB: expectation is that when we run this test, the device will be
 596   // completed booted, will be on charger, and will not have the camera
 597   // active.
 598   EXPECT_FALSE(get_booting());
 599   EXPECT_TRUE(get_charging());
 600   EXPECT_FALSE(get_camera_active());
 601 }
 602
 603 TEST_F(PerfProfdTest, BasicRunWithCannedPerf)
 604 {
 605   //
 606   // Verify the portion of the daemon that reads and encodes
 607   // perf.data files. Here we run the encoder on a canned perf.data
 608   // file and verify that the resulting protobuf contains what
 609   // we think it should contain.
 610   //
 611   std::string input_perf_data(test_dir);
 612   input_perf_data += "/canned.perf.data";
 613
 614   // Set up config to avoid these annotations (they are tested elsewhere)
 615   ConfigReader config_reader;
 616   config_reader.overrideUnsignedEntry("collect_cpu_utilization", 0);
 617   config_reader.overrideUnsignedEntry("collect_charging_state", 0);
 618   config_reader.overrideUnsignedEntry("collect_camera_active", 0);
 619   PerfProfdRunner::LoggingConfig config;
 620   config_reader.FillConfig(&config);
 621
 622   // Kick off encoder and check return code
 623   PROFILE_RESULT result =
 624       encode_to_proto(input_perf_data, encoded_file_path(dest_dir, 0).c_str(), config, 0, nullptr);
 625   ASSERT_EQ(OK_PROFILE_COLLECTION, result) << test_logger.JoinTestLog(" ");
 626
 627   // Read and decode the resulting perf.data.encoded file
 628   wireless_android_play_playlog::AndroidPerfProfile encodedProfile;
 629   readEncodedProfile(dest_dir,
 630                      "BasicRunWithCannedPerf",
 631                      encodedProfile);
 632
 633   // Expect 48 programs
 634   EXPECT_EQ(48, encodedProfile.programs_size());
 635
 636   // Check a couple of load modules
 637   { const auto &lm0 = encodedProfile.load_modules(0);
 638     std::string act_lm0 = encodedLoadModuleToString(lm0);
 639     std::string sqact0 = squeezeWhite(act_lm0, "actual for lm 0");
 640     const std::string expected_lm0 = RAW_RESULT(
 641         name: "/data/app/com.google.android.apps.plus-1/lib/arm/libcronet.so"
 642                                                 );
 643     std::string sqexp0 = squeezeWhite(expected_lm0, "expected_lm0");
 644     EXPECT_STREQ(sqexp0.c_str(), sqact0.c_str());
 645   }
 646   { const auto &lm9 = encodedProfile.load_modules(9);
 647     std::string act_lm9 = encodedLoadModuleToString(lm9);
 648     std::string sqact9 = squeezeWhite(act_lm9, "actual for lm 9");
 649     const std::string expected_lm9 = RAW_RESULT(
 650         name: "/system/lib/libandroid_runtime.so" build_id: "8164ed7b3a8b8f5a220d027788922510"
 651                                                 );
 652     std::string sqexp9 = squeezeWhite(expected_lm9, "expected_lm9");
 653     EXPECT_STREQ(sqexp9.c_str(), sqact9.c_str());
 654   }
 655
 656   // Examine some of the samples now
 657   { const auto &p1 = encodedProfile.programs(9);
 658     const auto &lm1 = p1.modules(0);
 659     std::string act_lm1 = encodedModuleSamplesToString(lm1);
 660     std::string sqact1 = squeezeWhite(act_lm1, "actual for lm1");
 661     const std::string expected_lm1 = RAW_RESULT(
 662         load_module_id: 9 address_samples { address: 296100 count: 1 }
 663                                                 );
 664     std::string sqexp1 = squeezeWhite(expected_lm1, "expected_lm1");
 665     EXPECT_STREQ(sqexp1.c_str(), sqact1.c_str());
 666   }
 667   { const auto &p1 = encodedProfile.programs(11);
 668     const auto &lm2 = p1.modules(0);
 669     std::string act_lm2 = encodedModuleSamplesToString(lm2);
 670     std::string sqact2 = squeezeWhite(act_lm2, "actual for lm2");
 671     const std::string expected_lm2 = RAW_RESULT(
 672         load_module_id: 2
 673         address_samples { address: 28030244 count: 1 }
 674         address_samples { address: 29657840 count: 1 }
 675                                                 );
 676     std::string sqexp2 = squeezeWhite(expected_lm2, "expected_lm2");
 677     EXPECT_STREQ(sqexp2.c_str(), sqact2.c_str());
 678   }
 679 }
 680
 681 TEST_F(PerfProfdTest, BasicRunWithCannedPerfWithSymbolizer)
 682 {
 683   //
 684   // Verify the portion of the daemon that reads and encodes
 685   // perf.data files. Here we run the encoder on a canned perf.data
 686   // file and verify that the resulting protobuf contains what
 687   // we think it should contain.
 688   //
 689   std::string input_perf_data(test_dir);
 690   input_perf_data += "/canned.perf.data";
 691
 692   // Set up config to avoid these annotations (they are tested elsewhere)
 693   ConfigReader config_reader;
 694   config_reader.overrideUnsignedEntry("collect_cpu_utilization", 0);
 695   config_reader.overrideUnsignedEntry("collect_charging_state", 0);
 696   config_reader.overrideUnsignedEntry("collect_camera_active", 0);
 697   PerfProfdRunner::LoggingConfig config;
 698   config_reader.FillConfig(&config);
 699
 700   // Kick off encoder and check return code
 701   struct TestSymbolizer : public perfprofd::Symbolizer {
 702     std::string Decode(const std::string& dso, uint64_t address) override {
 703       return dso + "@" + std::to_string(address);
 704     }
 705   };
 706   TestSymbolizer test_symbolizer;
 707   PROFILE_RESULT result =
 708       encode_to_proto(input_perf_data,
 709                       encoded_file_path(dest_dir, 0).c_str(),
 710                       config,
 711                       0,
 712                       &test_symbolizer);
 713   ASSERT_EQ(OK_PROFILE_COLLECTION, result);
 714
 715   // Read and decode the resulting perf.data.encoded file
 716   wireless_android_play_playlog::AndroidPerfProfile encodedProfile;
 717   readEncodedProfile(dest_dir,
 718                      "BasicRunWithCannedPerf",
 719                      encodedProfile);
 720
 721   // Expect 45 programs
 722   EXPECT_EQ(48, encodedProfile.programs_size());
 723
 724   // Check a couple of load modules
 725   { const auto &lm0 = encodedProfile.load_modules(0);
 726     std::string act_lm0 = encodedLoadModuleToString(lm0);
 727     std::string sqact0 = squeezeWhite(act_lm0, "actual for lm 0");
 728     const std::string expected_lm0 = RAW_RESULT(
 729         name: "/data/app/com.google.android.apps.plus-1/lib/arm/libcronet.so"
 730         symbol: "/data/app/com.google.android.apps.plus-1/lib/arm/libcronet.so@310106"
 731         symbol: "/data/app/com.google.android.apps.plus-1/lib/arm/libcronet.so@1949952"
 732                                                 );
 733     std::string sqexp0 = squeezeWhite(expected_lm0, "expected_lm0");
 734     EXPECT_STREQ(sqexp0.c_str(), sqact0.c_str());
 735   }
 736   { const auto &lm9 = encodedProfile.load_modules(9);
 737     std::string act_lm9 = encodedLoadModuleToString(lm9);
 738     std::string sqact9 = squeezeWhite(act_lm9, "actual for lm 9");
 739     const std::string expected_lm9 = RAW_RESULT(
 740         name: "/system/lib/libandroid_runtime.so" build_id: "8164ed7b3a8b8f5a220d027788922510"
 741                                                 );
 742     std::string sqexp9 = squeezeWhite(expected_lm9, "expected_lm9");
 743     EXPECT_STREQ(sqexp9.c_str(), sqact9.c_str());
 744   }
 745
 746   // Examine some of the samples now
 747   { const auto &p1 = encodedProfile.programs(9);
 748     const auto &lm1 = p1.modules(0);
 749     std::string act_lm1 = encodedModuleSamplesToString(lm1);
 750     std::string sqact1 = squeezeWhite(act_lm1, "actual for lm1");
 751     const std::string expected_lm1 = RAW_RESULT(
 752         load_module_id: 9 address_samples { address: 296100 count: 1 }
 753                                                 );
 754     std::string sqexp1 = squeezeWhite(expected_lm1, "expected_lm1");
 755     EXPECT_STREQ(sqexp1.c_str(), sqact1.c_str());
 756   }
 757   { const auto &p1 = encodedProfile.programs(11);
 758     const auto &lm2 = p1.modules(0);
 759     std::string act_lm2 = encodedModuleSamplesToString(lm2);
 760     std::string sqact2 = squeezeWhite(act_lm2, "actual for lm2");
 761     const std::string expected_lm2 = RAW_RESULT(
 762         load_module_id: 2
 763         address_samples { address: 18446744073709551615 count: 1 }
 764         address_samples { address: 18446744073709551614 count: 1 }
 765                                                 );
 766     std::string sqexp2 = squeezeWhite(expected_lm2, "expected_lm2");
 767     EXPECT_STREQ(sqexp2.c_str(), sqact2.c_str());
 768   }
 769 }
 770
 771 TEST_F(PerfProfdTest, CallchainRunWithCannedPerf)
 772 {
 773   // This test makes sure that the perf.data converter
 774   // can handle call chains.
 775   //
 776   std::string input_perf_data(test_dir);
 777   input_perf_data += "/callchain.canned.perf.data";
 778
 779   // Set up config to avoid these annotations (they are tested elsewhere)
 780   ConfigReader config_reader;
 781   config_reader.overrideUnsignedEntry("collect_cpu_utilization", 0);
 782   config_reader.overrideUnsignedEntry("collect_charging_state", 0);
 783   config_reader.overrideUnsignedEntry("collect_camera_active", 0);
 784   PerfProfdRunner::LoggingConfig config;
 785   config_reader.FillConfig(&config);
 786
 787   // Kick off encoder and check return code
 788   PROFILE_RESULT result =
 789       encode_to_proto(input_perf_data, encoded_file_path(dest_dir, 0).c_str(), config, 0, nullptr);
 790   ASSERT_EQ(OK_PROFILE_COLLECTION, result);
 791
 792   // Read and decode the resulting perf.data.encoded file
 793   wireless_android_play_playlog::AndroidPerfProfile encodedProfile;
 794   readEncodedProfile(dest_dir,
 795                      "BasicRunWithCannedPerf",
 796                      encodedProfile);
 797
 798
 799   // Expect 3 programs 8 load modules
 800   EXPECT_EQ(3, encodedProfile.programs_size());
 801   EXPECT_EQ(8, encodedProfile.load_modules_size());
 802
 803   // Check a couple of load modules
 804   { const auto &lm0 = encodedProfile.load_modules(0);
 805     std::string act_lm0 = encodedLoadModuleToString(lm0);
 806     std::string sqact0 = squeezeWhite(act_lm0, "actual for lm 0");
 807     const std::string expected_lm0 = RAW_RESULT(
 808         name: "/system/bin/dex2oat"
 809         build_id: "ee12bd1a1de39422d848f249add0afc4"
 810                                                 );
 811     std::string sqexp0 = squeezeWhite(expected_lm0, "expected_lm0");
 812     EXPECT_STREQ(sqexp0.c_str(), sqact0.c_str());
 813   }
 814   { const auto &lm1 = encodedProfile.load_modules(1);
 815     std::string act_lm1 = encodedLoadModuleToString(lm1);
 816     std::string sqact1 = squeezeWhite(act_lm1, "actual for lm 1");
 817     const std::string expected_lm1 = RAW_RESULT(
 818         name: "/system/bin/linker"
 819         build_id: "a36715f673a4a0aa76ef290124c516cc"
 820                                                 );
 821     std::string sqexp1 = squeezeWhite(expected_lm1, "expected_lm1");
 822     EXPECT_STREQ(sqexp1.c_str(), sqact1.c_str());
 823   }
 824
 825   // Examine some of the samples now
 826   { const auto &p0 = encodedProfile.programs(1);
 827     const auto &lm1 = p0.modules(0);
 828     std::string act_lm1 = encodedModuleSamplesToString(lm1);
 829     std::string sqact1 = squeezeWhite(act_lm1, "actual for lm1");
 830     const std::string expected_lm1 = RAW_RESULT(
 831         load_module_id: 0
 832         address_samples { address: 108552 count: 2 }
 833                                                 );
 834     std::string sqexp1 = squeezeWhite(expected_lm1, "expected_lm1");
 835     EXPECT_STREQ(sqexp1.c_str(), sqact1.c_str());
 836   }
 837   { const auto &p4 = encodedProfile.programs(2);
 838     const auto &lm2 = p4.modules(1);
 839     std::string act_lm2 = encodedModuleSamplesToString(lm2);
 840     std::string sqact2 = squeezeWhite(act_lm2, "actual for lm2");
 841     const std::string expected_lm2 = RAW_RESULT(
 842         load_module_id: 2 address_samples { address: 403913 count: 1 } address_samples { address: 840761 count: 1 } address_samples { address: 846481 count: 1 } address_samples { address: 999053 count: 1 } address_samples { address: 1012959 count: 1 } address_samples { address: 1524309 count: 1 } address_samples { address: 1580779 count: 1 } address_samples { address: 4287986288 count: 1 }
 843                                                 );
 844     std::string sqexp2 = squeezeWhite(expected_lm2, "expected_lm2");
 845     EXPECT_STREQ(sqexp2.c_str(), sqact2.c_str());
 846   }
 847 }
 848
 849 TEST_F(PerfProfdTest, BasicRunWithLivePerf)
 850 {
 851   //
 852   // Basic test to exercise the main loop of the daemon. It includes
 853   // a live 'perf' run
 854   //
 855   PerfProfdRunner runner(conf_dir);
 856   runner.addToConfig("only_debug_build=0");
 857   std::string ddparam("destination_directory="); ddparam += dest_dir;
 858   runner.addToConfig(ddparam);
 859   std::string cfparam("config_directory="); cfparam += conf_dir;
 860   runner.addToConfig(cfparam);
 861   runner.addToConfig("main_loop_iterations=1");
 862   runner.addToConfig("use_fixed_seed=12345678");
 863   runner.addToConfig("max_unprocessed_profiles=100");
 864   runner.addToConfig("collection_interval=9999");
 865   runner.addToConfig("sample_duration=2");
 866   // Avoid the symbolizer for spurious messages.
 867   runner.addToConfig("use_elf_symbolizer=0");
 868
 869   // Create semaphore file
 870   runner.create_semaphore_file();
 871
 872   // Kick off daemon
 873   int daemon_main_return_code = runner.invoke();
 874
 875   // Check return code from daemon
 876   ASSERT_EQ(0, daemon_main_return_code);
 877
 878   // Read and decode the resulting perf.data.encoded file
 879   wireless_android_play_playlog::AndroidPerfProfile encodedProfile;
 880   readEncodedProfile(dest_dir, "BasicRunWithLivePerf", encodedProfile);
 881
 882   // Examine what we get back. Since it's a live profile, we can't
 883   // really do much in terms of verifying the contents.
 884   EXPECT_LT(0, encodedProfile.programs_size());
 885
 886   // Verify log contents
 887   const std::string expected = std::string(
 888       "I: starting Android Wide Profiling daemon ") +
 889       "I: config file path set to " + conf_dir + "/perfprofd.conf " +
 890       RAW_RESULT(
 891       I: random seed set to 12345678
 892       I: sleep 674 seconds
 893       I: initiating profile collection
 894       I: sleep 2 seconds
 895       I: profile collection complete
 896       I: sleep 9325 seconds
 897       I: finishing Android Wide Profiling daemon
 898                                           );
 899   // check to make sure log excerpt matches
 900   CompareLogMessages(expandVars(expected), "BasicRunWithLivePerf", true);
 901 }
 902
 903 TEST_F(PerfProfdTest, MultipleRunWithLivePerf)
 904 {
 905   //
 906   // Basic test to exercise the main loop of the daemon. It includes
 907   // a live 'perf' run
 908   //
 909   PerfProfdRunner runner(conf_dir);
 910   runner.addToConfig("only_debug_build=0");
 911   std::string ddparam("destination_directory="); ddparam += dest_dir;
 912   runner.addToConfig(ddparam);
 913   std::string cfparam("config_directory="); cfparam += conf_dir;
 914   runner.addToConfig(cfparam);
 915   runner.addToConfig("main_loop_iterations=3");
 916   runner.addToConfig("use_fixed_seed=12345678");
 917   runner.addToConfig("collection_interval=9999");
 918   runner.addToConfig("sample_duration=2");
 919   // Avoid the symbolizer for spurious messages.
 920   runner.addToConfig("use_elf_symbolizer=0");
 921   runner.write_processed_file(1, 2);
 922
 923   // Create semaphore file
 924   runner.create_semaphore_file();
 925
 926   // Kick off daemon
 927   int daemon_main_return_code = runner.invoke();
 928
 929   // Check return code from daemon
 930   ASSERT_EQ(0, daemon_main_return_code);
 931
 932   // Read and decode the resulting perf.data.encoded file
 933   wireless_android_play_playlog::AndroidPerfProfile encodedProfile;
 934   readEncodedProfile(dest_dir, "BasicRunWithLivePerf", encodedProfile);
 935
 936   // Examine what we get back. Since it's a live profile, we can't
 937   // really do much in terms of verifying the contents.
 938   EXPECT_LT(0, encodedProfile.programs_size());
 939
 940   // Examine that encoded.1 file is removed while encoded.{0|2} exists.
 941   EXPECT_EQ(0, access(encoded_file_path(dest_dir, 0).c_str(), F_OK));
 942   EXPECT_NE(0, access(encoded_file_path(dest_dir, 1).c_str(), F_OK));
 943   EXPECT_EQ(0, access(encoded_file_path(dest_dir, 2).c_str(), F_OK));
 944
 945   // Verify log contents
 946   const std::string expected = std::string(
 947       "I: starting Android Wide Profiling daemon ") +
 948       "I: config file path set to " + conf_dir + "/perfprofd.conf " +
 949       RAW_RESULT(
 950       I: random seed set to 12345678
 951       I: sleep 674 seconds
 952       I: initiating profile collection
 953       I: sleep 2 seconds
 954       I: profile collection complete
 955       I: sleep 9325 seconds
 956       I: sleep 4974 seconds
 957       I: initiating profile collection
 958       I: sleep 2 seconds
 959       I: profile collection complete
 960       I: sleep 5025 seconds
 961       I: sleep 501 seconds
 962       I: initiating profile collection
 963       I: sleep 2 seconds
 964       I: profile collection complete
 965       I: sleep 9498 seconds
 966       I: finishing Android Wide Profiling daemon
 967                                           );
 968   // check to make sure log excerpt matches
 969   CompareLogMessages(expandVars(expected), "BasicRunWithLivePerf", true);
 970 }
 971
 972 TEST_F(PerfProfdTest, CallChainRunWithLivePerf)
 973 {
 974   //
 975   // Collect a callchain profile, so as to exercise the code in
 976   // perf_data post-processing that digests callchains.
 977   //
 978   PerfProfdRunner runner(conf_dir);
 979   std::string ddparam("destination_directory="); ddparam += dest_dir;
 980   runner.addToConfig(ddparam);
 981   std::string cfparam("config_directory="); cfparam += conf_dir;
 982   runner.addToConfig(cfparam);
 983   runner.addToConfig("main_loop_iterations=1");
 984   runner.addToConfig("use_fixed_seed=12345678");
 985   runner.addToConfig("max_unprocessed_profiles=100");
 986   runner.addToConfig("collection_interval=9999");
 987   runner.addToConfig("stack_profile=1");
 988   runner.addToConfig("sample_duration=2");
 989   // Avoid the symbolizer for spurious messages.
 990   runner.addToConfig("use_elf_symbolizer=0");
 991
 992   // Create semaphore file
 993   runner.create_semaphore_file();
 994
 995   // Kick off daemon
 996   int daemon_main_return_code = runner.invoke();
 997
 998   // Check return code from daemon
 999   ASSERT_EQ(0, daemon_main_return_code);
1000
1001   // Read and decode the resulting perf.data.encoded file
1002   wireless_android_play_playlog::AndroidPerfProfile encodedProfile;
1003   readEncodedProfile(dest_dir, "CallChainRunWithLivePerf", encodedProfile);
1004
1005   // Examine what we get back. Since it's a live profile, we can't
1006   // really do much in terms of verifying the contents.
1007   EXPECT_LT(0, encodedProfile.programs_size());
1008
1009   // Verify log contents
1010   const std::string expected = std::string(
1011       "I: starting Android Wide Profiling daemon ") +
1012       "I: config file path set to " + conf_dir + "/perfprofd.conf " +
1013       RAW_RESULT(
1014       I: random seed set to 12345678
1015       I: sleep 674 seconds
1016       I: initiating profile collection
1017       I: sleep 2 seconds
1018       I: profile collection complete
1019       I: sleep 9325 seconds
1020       I: finishing Android Wide Profiling daemon
1021                                           );
1022   // check to make sure log excerpt matches
1023   CompareLogMessages(expandVars(expected), "CallChainRunWithLivePerf", true);
1024 }
1025
1026 int main(int argc, char **argv) {
1027   // Always log to cerr, so that device failures are visible.
1028   android::base::SetLogger(android::base::StderrLogger);
1029
1030   CHECK(android::base::Realpath(argv[0], &gExecutableRealpath));
1031
1032   // switch to / before starting testing (perfprofd
1033   // should be location-independent)
1034   chdir("/");
1035   testing::InitGoogleTest(&argc, argv);
1036   return RUN_ALL_TESTS();
1037 }