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