OSDN Git Service

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