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