simpleperf/cmd_stat.cpp

   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 <inttypes.h>
  18 #include <signal.h>
  19 #include <stdio.h>
  20 #include <string.h>
  21
  22 #include <algorithm>
  23 #include <chrono>
  24 #include <set>
  25 #include <string>
  26 #include <vector>
  27
  28 #include <android-base/logging.h>
  29 #include <android-base/strings.h>
  30
  31 #include "command.h"
  32 #include "environment.h"
  33 #include "event_attr.h"
  34 #include "event_fd.h"
  35 #include "event_selection_set.h"
  36 #include "event_type.h"
  37 #include "scoped_signal_handler.h"
  38 #include "utils.h"
  39 #include "workload.h"
  40
  41 static std::vector<std::string> default_measured_event_types{
  42     "cpu-cycles",   "stalled-cycles-frontend", "stalled-cycles-backend",
  43     "instructions", "branch-instructions",     "branch-misses",
  44     "task-clock",   "context-switches",        "page-faults",
  45 };
  46
  47 static volatile bool signaled;
  48 static void signal_handler(int) {
  49   signaled = true;
  50 }
  51
  52 class StatCommand : public Command {
  53  public:
  54   StatCommand()
  55       : Command("stat", "gather performance counter information",
  56                 "Usage: simpleperf stat [options] [command [command-args]]\n"
  57                 "    Gather performance counter information of running [command].\n"
  58                 "    -a           Collect system-wide information.\n"
  59                 "    --cpu cpu_item1,cpu_item2,...\n"
  60                 "                 Collect information only on the selected cpus. cpu_item can\n"
  61                 "                 be a cpu number like 1, or a cpu range like 0-3.\n"
  62                 "    -e event1[:modifier1],event2[:modifier2],...\n"
  63                 "                 Select the event list to count. Use `simpleperf list` to find\n"
  64                 "                 all possible event names. Modifiers can be added to define\n"
  65                 "                 how the event should be monitored. Possible modifiers are:\n"
  66                 "                   u - monitor user space events only\n"
  67                 "                   k - monitor kernel space events only\n"
  68                 "    --no-inherit\n"
  69                 "                 Don't stat created child threads/processes.\n"
  70                 "    -p pid1,pid2,...\n"
  71                 "                 Stat events on existing processes. Mutually exclusive with -a.\n"
  72                 "    -t tid1,tid2,...\n"
  73                 "                 Stat events on existing threads. Mutually exclusive with -a.\n"
  74                 "    --verbose    Show result in verbose mode.\n"),
  75         verbose_mode_(false),
  76         system_wide_collection_(false),
  77         child_inherit_(true) {
  78     signaled = false;
  79     scoped_signal_handler_.reset(
  80         new ScopedSignalHandler({SIGCHLD, SIGINT, SIGTERM}, signal_handler));
  81   }
  82
  83   bool Run(const std::vector<std::string>& args);
  84
  85  private:
  86   bool ParseOptions(const std::vector<std::string>& args, std::vector<std::string>* non_option_args);
  87   bool AddMeasuredEventType(const std::string& event_type_name);
  88   bool AddDefaultMeasuredEventTypes();
  89   bool SetEventSelection();
  90   bool ShowCounters(const std::vector<CountersInfo>& counters, double duration_in_sec);
  91
  92   bool verbose_mode_;
  93   bool system_wide_collection_;
  94   bool child_inherit_;
  95   std::vector<pid_t> monitored_threads_;
  96   std::vector<int> cpus_;
  97   std::vector<EventTypeAndModifier> measured_event_types_;
  98   EventSelectionSet event_selection_set_;
  99
 100   std::unique_ptr<ScopedSignalHandler> scoped_signal_handler_;
 101 };
 102
 103 bool StatCommand::Run(const std::vector<std::string>& args) {
 104   // 1. Parse options, and use default measured event types if not given.
 105   std::vector<std::string> workload_args;
 106   if (!ParseOptions(args, &workload_args)) {
 107     return false;
 108   }
 109   if (measured_event_types_.empty()) {
 110     if (!AddDefaultMeasuredEventTypes()) {
 111       return false;
 112     }
 113   }
 114   if (!SetEventSelection()) {
 115     return false;
 116   }
 117
 118   // 2. Create workload.
 119   std::unique_ptr<Workload> workload;
 120   if (!workload_args.empty()) {
 121     workload = Workload::CreateWorkload(workload_args);
 122     if (workload == nullptr) {
 123       return false;
 124     }
 125   }
 126   if (!system_wide_collection_ && monitored_threads_.empty()) {
 127     if (workload != nullptr) {
 128       monitored_threads_.push_back(workload->GetPid());
 129       event_selection_set_.SetEnableOnExec(true);
 130     } else {
 131       LOG(ERROR) << "No threads to monitor. Try `simpleperf help stat` for help\n";
 132       return false;
 133     }
 134   }
 135
 136   // 3. Open perf_event_files.
 137   if (system_wide_collection_) {
 138     if (!event_selection_set_.OpenEventFilesForCpus(cpus_)) {
 139       return false;
 140     }
 141   } else {
 142     if (!event_selection_set_.OpenEventFilesForThreadsOnCpus(monitored_threads_, cpus_)) {
 143       return false;
 144     }
 145   }
 146
 147   // 4. Count events while workload running.
 148   auto start_time = std::chrono::steady_clock::now();
 149   if (workload != nullptr && !workload->Start()) {
 150     return false;
 151   }
 152   while (!signaled) {
 153     sleep(1);
 154   }
 155   auto end_time = std::chrono::steady_clock::now();
 156
 157   // 5. Read and print counters.
 158   std::vector<CountersInfo> counters;
 159   if (!event_selection_set_.ReadCounters(&counters)) {
 160     return false;
 161   }
 162   double duration_in_sec =
 163       std::chrono::duration_cast<std::chrono::duration<double>>(end_time - start_time).count();
 164   if (!ShowCounters(counters, duration_in_sec)) {
 165     return false;
 166   }
 167   return true;
 168 }
 169
 170 bool StatCommand::ParseOptions(const std::vector<std::string>& args,
 171                                std::vector<std::string>* non_option_args) {
 172   std::set<pid_t> tid_set;
 173   size_t i;
 174   for (i = 0; i < args.size() && args[i].size() > 0 && args[i][0] == '-'; ++i) {
 175     if (args[i] == "-a") {
 176       system_wide_collection_ = true;
 177     } else if (args[i] == "--cpu") {
 178       if (!NextArgumentOrError(args, &i)) {
 179         return false;
 180       }
 181       cpus_ = GetCpusFromString(args[i]);
 182     } else if (args[i] == "-e") {
 183       if (!NextArgumentOrError(args, &i)) {
 184         return false;
 185       }
 186       std::vector<std::string> event_types = android::base::Split(args[i], ",");
 187       for (auto& event_type : event_types) {
 188         if (!AddMeasuredEventType(event_type)) {
 189           return false;
 190         }
 191       }
 192     } else if (args[i] == "--no-inherit") {
 193       child_inherit_ = false;
 194     } else if (args[i] == "-p") {
 195       if (!NextArgumentOrError(args, &i)) {
 196         return false;
 197       }
 198       if (!GetValidThreadsFromProcessString(args[i], &tid_set)) {
 199         return false;
 200       }
 201     } else if (args[i] == "-t") {
 202       if (!NextArgumentOrError(args, &i)) {
 203         return false;
 204       }
 205       if (!GetValidThreadsFromThreadString(args[i], &tid_set)) {
 206         return false;
 207       }
 208     } else if (args[i] == "--verbose") {
 209       verbose_mode_ = true;
 210     } else {
 211       ReportUnknownOption(args, i);
 212       return false;
 213     }
 214   }
 215
 216   monitored_threads_.insert(monitored_threads_.end(), tid_set.begin(), tid_set.end());
 217   if (system_wide_collection_ && !monitored_threads_.empty()) {
 218     LOG(ERROR) << "Stat system wide and existing processes/threads can't be used at the same time.";
 219     return false;
 220   }
 221
 222   if (non_option_args != nullptr) {
 223     non_option_args->clear();
 224     for (; i < args.size(); ++i) {
 225       non_option_args->push_back(args[i]);
 226     }
 227   }
 228   return true;
 229 }
 230
 231 bool StatCommand::AddMeasuredEventType(const std::string& event_type_name) {
 232   std::unique_ptr<EventTypeAndModifier> event_type_modifier = ParseEventType(event_type_name);
 233   if (event_type_modifier == nullptr) {
 234     return false;
 235   }
 236   measured_event_types_.push_back(*event_type_modifier);
 237   return true;
 238 }
 239
 240 bool StatCommand::AddDefaultMeasuredEventTypes() {
 241   for (auto& name : default_measured_event_types) {
 242     // It is not an error when some event types in the default list are not supported by the kernel.
 243     const EventType* type = FindEventTypeByName(name);
 244     if (type != nullptr && IsEventAttrSupportedByKernel(CreateDefaultPerfEventAttr(*type))) {
 245       AddMeasuredEventType(name);
 246     }
 247   }
 248   if (measured_event_types_.empty()) {
 249     LOG(ERROR) << "Failed to add any supported default measured types";
 250     return false;
 251   }
 252   return true;
 253 }
 254
 255 bool StatCommand::SetEventSelection() {
 256   for (auto& event_type : measured_event_types_) {
 257     if (!event_selection_set_.AddEventType(event_type)) {
 258       return false;
 259     }
 260   }
 261   event_selection_set_.SetInherit(child_inherit_);
 262   return true;
 263 }
 264
 265 static std::string ReadableCountValue(uint64_t count,
 266                                       const EventTypeAndModifier& event_type_modifier) {
 267   if (event_type_modifier.event_type.name == "cpu-clock" ||
 268       event_type_modifier.event_type.name == "task-clock") {
 269     double value = count / 1e6;
 270     return android::base::StringPrintf("%lf(ms)", value);
 271   } else {
 272     std::string s = android::base::StringPrintf("%" PRIu64, count);
 273     for (size_t i = s.size() - 1, j = 1; i > 0; --i, ++j) {
 274       if (j == 3) {
 275         s.insert(s.begin() + i, ',');
 276         j = 0;
 277       }
 278     }
 279     return s;
 280   }
 281 }
 282
 283 struct CounterSummary {
 284   const EventTypeAndModifier* event_type;
 285   uint64_t count;
 286   double scale;
 287   std::string readable_count_str;
 288   std::string comment;
 289 };
 290
 291 static std::string GetCommentForSummary(const CounterSummary& summary,
 292                                         const std::vector<CounterSummary>& summaries,
 293                                         double duration_in_sec) {
 294   const std::string& type_name = summary.event_type->event_type.name;
 295   const std::string& modifier = summary.event_type->modifier;
 296   if (type_name == "task-clock") {
 297     double run_sec = summary.count / 1e9;
 298     double cpu_usage = run_sec / duration_in_sec;
 299     return android::base::StringPrintf("%lf%% cpu usage", cpu_usage * 100);
 300   }
 301   if (type_name == "cpu-clock") {
 302     return "";
 303   }
 304   if (type_name == "cpu-cycles") {
 305     double hz = summary.count / duration_in_sec;
 306     return android::base::StringPrintf("%lf GHz", hz / 1e9);
 307   }
 308   if (type_name == "instructions" && summary.count != 0) {
 309     for (auto& t : summaries) {
 310       if (t.event_type->event_type.name == "cpu-cycles" && t.event_type->modifier == modifier) {
 311         double cycles_per_instruction = t.count * 1.0 / summary.count;
 312         return android::base::StringPrintf("%lf cycles per instruction", cycles_per_instruction);
 313       }
 314     }
 315   }
 316   if (android::base::EndsWith(type_name, "-misses")) {
 317     std::string s;
 318     if (type_name == "cache-misses") {
 319       s = "cache-references";
 320     } else if (type_name == "branch-misses") {
 321       s = "branch-instructions";
 322     } else {
 323       s = type_name.substr(0, type_name.size() - strlen("-misses")) + "s";
 324     }
 325     for (auto& t : summaries) {
 326       if (t.event_type->event_type.name == s && t.event_type->modifier == modifier && t.count != 0) {
 327         double miss_rate = summary.count * 1.0 / t.count;
 328         return android::base::StringPrintf("%lf%% miss rate", miss_rate * 100);
 329       }
 330     }
 331   }
 332   double rate = summary.count / duration_in_sec;
 333   if (rate > 1e9) {
 334     return android::base::StringPrintf("%.3lf G/sec", rate / 1e9);
 335   }
 336   if (rate > 1e6) {
 337     return android::base::StringPrintf("%.3lf M/sec", rate / 1e6);
 338   }
 339   if (rate > 1e3) {
 340     return android::base::StringPrintf("%.3lf K/sec", rate / 1e3);
 341   }
 342   return android::base::StringPrintf("%.3lf /sec", rate);
 343 }
 344
 345 bool StatCommand::ShowCounters(const std::vector<CountersInfo>& counters, double duration_in_sec) {
 346   printf("Performance counter statistics:\n\n");
 347
 348   if (verbose_mode_) {
 349     for (auto& counters_info : counters) {
 350       const EventTypeAndModifier* event_type = counters_info.event_type;
 351       for (auto& counter_info : counters_info.counters) {
 352         printf("%s(tid %d, cpu %d): count %s, time_enabled %" PRIu64 ", time running %" PRIu64
 353                ", id %" PRIu64 "\n",
 354                event_type->name.c_str(), counter_info.tid, counter_info.cpu,
 355                ReadableCountValue(counter_info.counter.value, *event_type).c_str(),
 356                counter_info.counter.time_enabled, counter_info.counter.time_running,
 357                counter_info.counter.id);
 358       }
 359     }
 360   }
 361
 362   std::vector<CounterSummary> summaries;
 363   for (auto& counters_info : counters) {
 364     uint64_t value_sum = 0;
 365     uint64_t time_enabled_sum = 0;
 366     uint64_t time_running_sum = 0;
 367     for (auto& counter_info : counters_info.counters) {
 368       value_sum += counter_info.counter.value;
 369       time_enabled_sum += counter_info.counter.time_enabled;
 370       time_running_sum += counter_info.counter.time_running;
 371     }
 372     double scale = 1.0;
 373     uint64_t scaled_count = value_sum;
 374     if (time_running_sum < time_enabled_sum) {
 375       if (time_running_sum == 0) {
 376         scaled_count = 0;
 377       } else {
 378         scale = static_cast<double>(time_enabled_sum) / time_running_sum;
 379         scaled_count = static_cast<uint64_t>(scale * value_sum);
 380       }
 381     }
 382     CounterSummary summary;
 383     summary.event_type = counters_info.event_type;
 384     summary.count = scaled_count;
 385     summary.scale = scale;
 386     summary.readable_count_str = ReadableCountValue(summary.count, *summary.event_type);
 387     summaries.push_back(summary);
 388   }
 389
 390   for (auto& summary : summaries) {
 391     summary.comment = GetCommentForSummary(summary, summaries, duration_in_sec);
 392   }
 393
 394   size_t count_column_width = 0;
 395   size_t name_column_width = 0;
 396   size_t comment_column_width = 0;
 397   for (auto& summary : summaries) {
 398     count_column_width = std::max(count_column_width, summary.readable_count_str.size());
 399     name_column_width = std::max(name_column_width, summary.event_type->name.size());
 400     comment_column_width = std::max(comment_column_width, summary.comment.size());
 401   }
 402
 403   for (auto& summary : summaries) {
 404     printf("  %*s  %-*s   # %-*s   (%.0lf%%)\n", static_cast<int>(count_column_width),
 405            summary.readable_count_str.c_str(), static_cast<int>(name_column_width),
 406            summary.event_type->name.c_str(), static_cast<int>(comment_column_width),
 407            summary.comment.c_str(), 1.0 / summary.scale * 100);
 408   }
 409
 410   printf("\nTotal test time: %lf seconds.\n", duration_in_sec);
 411   return true;
 412 }
 413
 414 __attribute__((constructor)) static void RegisterStatCommand() {
 415   RegisterCommand("stat", [] { return std::unique_ptr<Command>(new StatCommand); });
 416 }