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 <gtest/gtest.h>
  18 #include <algorithm>
  19 #include <cctype>
  20 #include <string>
  21 #include <regex>
  22 #include <stdio.h>
  23 #include <sys/types.h>
  24 #include <sys/stat.h>
  25 #include <fcntl.h>
  26
  27 #include "perfprofdcore.h"
  28 #include "perfprofdutils.h"
  29 #include "perfprofdmockutils.h"
  30
  31 #include "perf_profile.pb.h"
  32 #include "google/protobuf/text_format.h"
  33
  34 //
  35 // Set to argv[0] on startup
  36 //
  37 static const char *executable_path;
  38
  39 //
  40 // test_dir is the directory containing the test executable and
  41 // any files associated with the test (will be created by the harness).
  42 //
  43 // dest_dir is a subdirectory of test_dir that we'll create on the fly
  44 // at the start of each testpoint (into which new files can be written),
  45 // then delete at end of testpoint.
  46 //
  47 static std::string test_dir;
  48 static std::string dest_dir;
  49
  50 // Path to perf executable on device
  51 #define PERFPATH "/system/bin/perf"
  52
  53 // Temporary config file that we will emit for the daemon to read
  54 #define CONFIGFILE "perfprofd.conf"
  55
  56 static std::string encoded_file_path()
  57 {
  58   std::string path(dest_dir);
  59   path += "/perf.data.encoded";
  60   return path;
  61 }
  62
  63 class PerfProfdTest : public testing::Test {
  64  protected:
  65   virtual void SetUp() {
  66     mock_perfprofdutils_init();
  67     create_dest_dir();
  68     yesclean();
  69   }
  70
  71   virtual void TearDown() {
  72     mock_perfprofdutils_finish();
  73   }
  74
  75   void noclean() {
  76     clean_ = false;
  77   }
  78   void yesclean() {
  79     clean_ = true;
  80   }
  81
  82  private:
  83   bool clean_;
  84
  85   void create_dest_dir() {
  86     setup_dirs();
  87     ASSERT_FALSE(dest_dir == "");
  88     if (clean_) {
  89       std::string cmd("rm -rf ");
  90       cmd += dest_dir;
  91       system(cmd.c_str());
  92     }
  93     std::string cmd("mkdir -p ");
  94     cmd += dest_dir;
  95     system(cmd.c_str());
  96   }
  97
  98   void setup_dirs()
  99   {
 100     if (test_dir == "") {
 101       ASSERT_TRUE(executable_path != nullptr);
 102       std::string s(executable_path);
 103       auto found = s.find_last_of("/");
 104       test_dir = s.substr(0,found);
 105       dest_dir = test_dir;
 106       dest_dir += "/tmp";
 107     }
 108   }
 109
 110 };
 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 /// Helper class to kick off a run of the perfprofd daemon with a specific
 138 /// config file.
 139 ///
 140 class PerfProfdRunner {
 141  public:
 142   PerfProfdRunner()
 143       : config_path_(test_dir)
 144   {
 145     config_path_ += "/" CONFIGFILE;
 146   }
 147
 148   ~PerfProfdRunner()
 149   {
 150   }
 151
 152   void addToConfig(const std::string &line)
 153   {
 154     config_text_ += line;
 155     config_text_ += "\n";
 156   }
 157
 158   void remove_semaphore_file()
 159   {
 160     std::string semaphore(test_dir);
 161     semaphore += "/" SEMAPHORE_FILENAME;
 162     unlink(semaphore.c_str());
 163   }
 164
 165   void create_semaphore_file()
 166   {
 167     std::string semaphore(test_dir);
 168     semaphore += "/" SEMAPHORE_FILENAME;
 169     close(open(semaphore.c_str(), O_WRONLY|O_CREAT));
 170   }
 171
 172   int invoke()
 173   {
 174     static const char *argv[3] = { "perfprofd", "-c", "" };
 175     argv[2] = config_path_.c_str();
 176
 177     writeConfigFile(config_path_, config_text_);
 178
 179     // execute daemon main
 180     return perfprofd_main(3, (char **) argv);
 181   }
 182
 183  private:
 184   std::string config_path_;
 185   std::string config_text_;
 186
 187   void writeConfigFile(const std::string &config_path,
 188                        const std::string &config_text)
 189   {
 190     FILE *fp = fopen(config_path.c_str(), "w");
 191     ASSERT_TRUE(fp != nullptr);
 192     fprintf(fp, "%s\n", config_text.c_str());
 193     fclose(fp);
 194   }
 195 };
 196
 197 //......................................................................
 198
 199 static void readEncodedProfile(const char *testpoint,
 200                                wireless_android_play_playlog::AndroidPerfProfile &encodedProfile)
 201 {
 202   struct stat statb;
 203   int perf_data_stat_result = stat(encoded_file_path().c_str(), &statb);
 204   ASSERT_NE(-1, perf_data_stat_result);
 205
 206   // read
 207   std::string encoded;
 208   encoded.resize(statb.st_size);
 209   FILE *ifp = fopen(encoded_file_path().c_str(), "r");
 210   ASSERT_NE(nullptr, ifp);
 211   size_t items_read = fread((void*) encoded.data(), statb.st_size, 1, ifp);
 212   ASSERT_EQ(1, items_read);
 213   fclose(ifp);
 214
 215   // decode
 216   encodedProfile.ParseFromString(encoded);
 217 }
 218
 219 static std::string encodedLoadModuleToString(const wireless_android_play_playlog::LoadModule &lm)
 220 {
 221   std::stringstream ss;
 222   ss << "name: \"" << lm.name() << "\"\n";
 223   if (lm.build_id() != "") {
 224     ss << "build_id: \"" << lm.build_id() << "\"\n";
 225   }
 226   return ss.str();
 227 }
 228
 229 static std::string encodedModuleSamplesToString(const wireless_android_play_playlog::LoadModuleSamples &mod)
 230 {
 231   std::stringstream ss;
 232
 233   ss << "load_module_id: " << mod.load_module_id() << "\n";
 234   for (size_t k = 0; k < mod.address_samples_size(); k++) {
 235     const auto &sample = mod.address_samples(k);
 236     ss << "  address_samples {\n";
 237     for (size_t l = 0; l < mod.address_samples(k).address_size();
 238          l++) {
 239       auto address = mod.address_samples(k).address(l);
 240       ss << "    address: " << address << "\n";
 241     }
 242     ss << "    count: " << sample.count() << "\n";
 243     ss << "  }\n";
 244   }
 245   return ss.str();
 246 }
 247
 248 #define RAW_RESULT(x) #x
 249
 250 //
 251 // Check to see if the log messages emitted by the daemon
 252 // match the expected result. By default we use a partial
 253 // match, e.g. if we see the expected excerpt anywhere in the
 254 // result, it's a match (for exact match, set exact to true)
 255 //
 256 static void compareLogMessages(const std::string &actual,
 257                                const std::string &expected,
 258                                const char *testpoint,
 259                                bool exactMatch=false)
 260 {
 261    std::string sqexp = squeezeWhite(expected, "expected");
 262    std::string sqact = squeezeWhite(actual, "actual");
 263    if (exactMatch) {
 264      EXPECT_STREQ(sqexp.c_str(), sqact.c_str());
 265    } else {
 266      std::size_t foundpos = sqact.find(sqexp);
 267      bool wasFound = true;
 268      if (foundpos == std::string::npos) {
 269        std::cerr << testpoint << ": expected result not found\n";
 270        std::cerr << " Actual: \"" << sqact << "\"\n";
 271        std::cerr << " Expected: \"" << sqexp << "\"\n";
 272        wasFound = false;
 273      }
 274      EXPECT_TRUE(wasFound);
 275    }
 276 }
 277
 278 TEST_F(PerfProfdTest, MissingGMS)
 279 {
 280   //
 281   // AWP requires cooperation between the daemon and the GMS core
 282   // piece. If we're running on a device that has an old or damaged
 283   // version of GMS core, then the config directory we're interested in
 284   // may not be there. This test insures that the daemon does the
 285   // right thing in this case.
 286   //
 287   PerfProfdRunner runner;
 288   runner.addToConfig("only_debug_build=0");
 289   runner.addToConfig("trace_config_read=1");
 290   runner.addToConfig("config_directory=/does/not/exist");
 291   runner.addToConfig("main_loop_iterations=1");
 292   runner.addToConfig("use_fixed_seed=1");
 293   runner.addToConfig("collection_interval=100");
 294
 295   // Kick off daemon
 296   int daemon_main_return_code = runner.invoke();
 297
 298   // Check return code from daemon
 299   EXPECT_EQ(0, daemon_main_return_code);
 300
 301   // Verify log contents
 302   const std::string expected = RAW_RESULT(
 303       I: sleep 90 seconds
 304       W: unable to open config directory /does/not/exist: (No such file or directory)
 305       I: profile collection skipped (missing config directory)
 306                                           );
 307
 308   // check to make sure entire log matches
 309   compareLogMessages(mock_perfprofdutils_getlogged(),
 310                      expected, "MissingGMS");
 311 }
 312
 313
 314 TEST_F(PerfProfdTest, MissingOptInSemaphoreFile)
 315 {
 316   //
 317   // Android device owners must opt in to "collect and report usage
 318   // data" in order for us to be able to collect profiles. The opt-in
 319   // check is performed in the GMS core component; if the check
 320   // passes, then it creates a semaphore file for the daemon to pick
 321   // up on.
 322   //
 323   PerfProfdRunner runner;
 324   runner.addToConfig("only_debug_build=0");
 325   std::string cfparam("config_directory="); cfparam += test_dir;
 326   runner.addToConfig(cfparam);
 327   std::string ddparam("destination_directory="); ddparam += dest_dir;
 328   runner.addToConfig(ddparam);
 329   runner.addToConfig("main_loop_iterations=1");
 330   runner.addToConfig("use_fixed_seed=1");
 331   runner.addToConfig("collection_interval=100");
 332
 333   runner.remove_semaphore_file();
 334
 335   // Kick off daemon
 336   int daemon_main_return_code = runner.invoke();
 337
 338   // Check return code from daemon
 339   EXPECT_EQ(0, daemon_main_return_code);
 340
 341   // Verify log contents
 342   const std::string expected = RAW_RESULT(
 343       I: profile collection skipped (missing semaphore file)
 344                                           );
 345   // check to make sure log excerpt matches
 346   compareLogMessages(mock_perfprofdutils_getlogged(),
 347                      expected, "MissingOptInSemaphoreFile");
 348 }
 349
 350 TEST_F(PerfProfdTest, MissingPerfExecutable)
 351 {
 352   //
 353   // Perfprofd uses the 'simpleperf' tool to collect profiles
 354   // (although this may conceivably change in the future). This test
 355   // checks to make sure that if 'simpleperf' is not present we bail out
 356   // from collecting profiles.
 357   //
 358   PerfProfdRunner runner;
 359   runner.addToConfig("only_debug_build=0");
 360   runner.addToConfig("trace_config_read=1");
 361   std::string cfparam("config_directory="); cfparam += test_dir;
 362   runner.addToConfig(cfparam);
 363   std::string ddparam("destination_directory="); ddparam += dest_dir;
 364   runner.addToConfig(ddparam);
 365   runner.addToConfig("main_loop_iterations=1");
 366   runner.addToConfig("use_fixed_seed=1");
 367   runner.addToConfig("collection_interval=100");
 368   runner.addToConfig("perf_path=/does/not/exist");
 369
 370   // Create semaphore file
 371   runner.create_semaphore_file();
 372
 373   // Kick off daemon
 374   int daemon_main_return_code = runner.invoke();
 375
 376   // Check return code from daemon
 377   EXPECT_EQ(0, daemon_main_return_code);
 378
 379   // expected log contents
 380   const std::string expected = RAW_RESULT(
 381       I: profile collection skipped (missing 'perf' executable)
 382                                           );
 383   // check to make sure log excerpt matches
 384   compareLogMessages(mock_perfprofdutils_getlogged(),
 385                      expected, "MissingPerfExecutable");
 386 }
 387
 388 TEST_F(PerfProfdTest, BadPerfRun)
 389 {
 390   //
 391   // Perf tools tend to be tightly coupled with a specific kernel
 392   // version -- if things are out of sync perf could fail or
 393   // crash. This test makes sure that we detect such a case and log
 394   // the error.
 395   //
 396   PerfProfdRunner runner;
 397   runner.addToConfig("only_debug_build=0");
 398   std::string cfparam("config_directory="); cfparam += test_dir;
 399   runner.addToConfig(cfparam);
 400   std::string ddparam("destination_directory="); ddparam += dest_dir;
 401   runner.addToConfig(ddparam);
 402   runner.addToConfig("main_loop_iterations=1");
 403   runner.addToConfig("use_fixed_seed=1");
 404   runner.addToConfig("collection_interval=100");
 405   runner.addToConfig("perf_path=/system/bin/false");
 406
 407   // Create semaphore file
 408   runner.create_semaphore_file();
 409
 410   // Kick off daemon
 411   int daemon_main_return_code = runner.invoke();
 412
 413   // Check return code from daemon
 414   EXPECT_EQ(0, daemon_main_return_code);
 415
 416   // Verify log contents
 417   const std::string expected = RAW_RESULT(
 418       I: profile collection failed (perf record returned bad exit status)
 419                                           );
 420
 421   // check to make sure log excerpt matches
 422   compareLogMessages(mock_perfprofdutils_getlogged(),
 423                      expected, "BadPerfRun");
 424 }
 425
 426 TEST_F(PerfProfdTest, ConfigFileParsing)
 427 {
 428   //
 429   // Gracefully handly malformed items in the config file
 430   //
 431   PerfProfdRunner runner;
 432   runner.addToConfig("only_debug_build=0");
 433   runner.addToConfig("main_loop_iterations=1");
 434   runner.addToConfig("collection_interval=100");
 435   runner.addToConfig("use_fixed_seed=1");
 436   runner.addToConfig("destination_directory=/does/not/exist");
 437
 438   // assorted bad syntax
 439   runner.addToConfig("collection_interval=0");
 440   runner.addToConfig("collection_interval=-1");
 441   runner.addToConfig("collection_interval=2");
 442   runner.addToConfig("nonexistent_key=something");
 443   runner.addToConfig("no_equals_stmt");
 444
 445   // Kick off daemon
 446   int daemon_main_return_code = runner.invoke();
 447
 448   // Check return code from daemon
 449   EXPECT_EQ(0, daemon_main_return_code);
 450
 451   // Verify log contents
 452   const std::string expected = RAW_RESULT(
 453       W: line 6: specified value 0 for 'collection_interval' outside permitted range [100 4294967295] (ignored)
 454       W: line 7: malformed unsigned value (ignored)
 455       W: line 8: specified value 2 for 'collection_interval' outside permitted range [100 4294967295] (ignored)
 456       W: line 9: unknown option 'nonexistent_key' ignored
 457       W: line 10: line malformed (no '=' found)
 458                                           );
 459
 460   // check to make sure log excerpt matches
 461   compareLogMessages(mock_perfprofdutils_getlogged(),
 462                      expected, "ConfigFileParsing");
 463 }
 464
 465 TEST_F(PerfProfdTest, BasicRunWithCannedPerf)
 466 {
 467   //
 468   // Verify the portion of the daemon that reads and encodes
 469   // perf.data files. Here we run the encoder on a canned perf.data
 470   // file and verify that the resulting protobuf contains what
 471   // we think it should contain.
 472   //
 473   std::string input_perf_data(test_dir);
 474   input_perf_data += "/canned.perf.data";
 475
 476   // Kick off encoder and check return code
 477   PROFILE_RESULT result =
 478       encode_to_proto(input_perf_data, encoded_file_path());
 479   EXPECT_EQ(OK_PROFILE_COLLECTION, result);
 480
 481   // Read and decode the resulting perf.data.encoded file
 482   wireless_android_play_playlog::AndroidPerfProfile encodedProfile;
 483   readEncodedProfile("BasicRunWithCannedPerf",
 484                      encodedProfile);
 485
 486   // Expect 29 load modules
 487   EXPECT_EQ(29, encodedProfile.programs_size());
 488
 489   // Check a couple of load modules
 490   { const auto &lm0 = encodedProfile.load_modules(0);
 491     std::string act_lm0 = encodedLoadModuleToString(lm0);
 492     std::string sqact0 = squeezeWhite(act_lm0, "actual for lm 0");
 493     const std::string expected_lm0 = RAW_RESULT(
 494         name: "/data/app/com.google.android.apps.plus-1/lib/arm/libcronet.so"
 495                                                 );
 496     std::string sqexp0 = squeezeWhite(expected_lm0, "expected_lm0");
 497     EXPECT_STREQ(sqexp0.c_str(), sqact0.c_str());
 498   }
 499   { const auto &lm9 = encodedProfile.load_modules(9);
 500     std::string act_lm9 = encodedLoadModuleToString(lm9);
 501     std::string sqact9 = squeezeWhite(act_lm9, "actual for lm 9");
 502     const std::string expected_lm9 = RAW_RESULT(
 503         name: "/system/lib/libandroid_runtime.so" build_id: "8164ed7b3a8b8f5a220d027788922510"
 504                                                 );
 505     std::string sqexp9 = squeezeWhite(expected_lm9, "expected_lm9");
 506     EXPECT_STREQ(sqexp9.c_str(), sqact9.c_str());
 507   }
 508
 509   // Examine some of the samples now
 510   { const auto &p1 = encodedProfile.programs(0);
 511     const auto &lm1 = p1.modules(0);
 512     std::string act_lm1 = encodedModuleSamplesToString(lm1);
 513     std::string sqact1 = squeezeWhite(act_lm1, "actual for lm1");
 514     const std::string expected_lm1 = RAW_RESULT(
 515         load_module_id: 9 address_samples { address: 296100 count: 1 }
 516                                                 );
 517     std::string sqexp1 = squeezeWhite(expected_lm1, "expected_lm1");
 518     EXPECT_STREQ(sqexp1.c_str(), sqact1.c_str());
 519   }
 520   { const auto &p1 = encodedProfile.programs(2);
 521     const auto &lm2 = p1.modules(0);
 522     std::string act_lm2 = encodedModuleSamplesToString(lm2);
 523     std::string sqact2 = squeezeWhite(act_lm2, "actual for lm2");
 524     const std::string expected_lm2 = RAW_RESULT(
 525         load_module_id: 2
 526         address_samples { address: 28030244 count: 1 }
 527         address_samples { address: 29657840 count: 1 }
 528                                                 );
 529     std::string sqexp2 = squeezeWhite(expected_lm2, "expected_lm2");
 530     EXPECT_STREQ(sqexp2.c_str(), sqact2.c_str());
 531   }
 532 }
 533
 534 TEST_F(PerfProfdTest, BasicRunWithLivePerf)
 535 {
 536   //
 537   // Basic test to exercise the main loop of the daemon. It includes
 538   // a live 'perf' run
 539   //
 540   PerfProfdRunner runner;
 541   runner.addToConfig("only_debug_build=0");
 542   std::string ddparam("destination_directory="); ddparam += dest_dir;
 543   runner.addToConfig(ddparam);
 544   std::string cfparam("config_directory="); cfparam += test_dir;
 545   runner.addToConfig(cfparam);
 546   runner.addToConfig("main_loop_iterations=1");
 547   runner.addToConfig("use_fixed_seed=12345678");
 548   runner.addToConfig("collection_interval=9999");
 549   runner.addToConfig("sample_duration=5");
 550
 551   // Create semaphore file
 552   runner.create_semaphore_file();
 553
 554   // Kick off daemon
 555   int daemon_main_return_code = runner.invoke();
 556
 557   // Check return code from daemon
 558   EXPECT_EQ(0, daemon_main_return_code);
 559
 560   // Read and decode the resulting perf.data.encoded file
 561   wireless_android_play_playlog::AndroidPerfProfile encodedProfile;
 562   readEncodedProfile("BasicRunWithLivePerf", encodedProfile);
 563
 564   // Examine what we get back. Since it's a live profile, we can't
 565   // really do much in terms of verifying the contents.
 566   EXPECT_LT(0, encodedProfile.programs_size());
 567
 568   // Verify log contents
 569   const std::string expected = RAW_RESULT(
 570       I: starting Android Wide Profiling daemon
 571       I: config file path set to /data/nativetest/perfprofd_test/perfprofd.conf
 572       I: random seed set to 12345678
 573       I: sleep 674 seconds
 574       I: initiating profile collection
 575       I: profile collection complete
 576       I: sleep 9325 seconds
 577       I: finishing Android Wide Profiling daemon
 578                                           );
 579   // check to make sure log excerpt matches
 580   compareLogMessages(mock_perfprofdutils_getlogged(),
 581                      expected, "BasicRunWithLivePerf", true);
 582 }
 583
 584 int main(int argc, char **argv) {
 585   executable_path = argv[0];
 586   // switch to / before starting testing (perfprofd
 587   // should be location-independent)
 588   chdir("/");
 589   testing::InitGoogleTest(&argc, argv);
 590   return RUN_ALL_TESTS();
 591 }