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