Home | History | Annotate | Download | only in ftrace 
      1 /*
      2  * Copyright (C) 2018 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 "src/traced/probes/ftrace/ftrace_config_muxer.h"
     18 
     19 #include <stdint.h>
     20 #include <string.h>
     21 #include <sys/types.h>
     22 #include <unistd.h>
     23 
     24 #include <algorithm>
     25 
     26 #include "perfetto/base/utils.h"
     27 #include "src/traced/probes/ftrace/atrace_wrapper.h"
     28 
     29 namespace perfetto {
     30 namespace {
     31 
     32 // trace_clocks in preference order.
     33 constexpr const char* kClocks[] = {"boot", "global", "local"};
     34 
     35 constexpr int kDefaultPerCpuBufferSizeKb = 2 * 1024;  // 2mb
     36 constexpr int kMaxPerCpuBufferSizeKb = 64 * 1024;  // 64mb
     37 
     38 void AddEventGroup(const ProtoTranslationTable* table,
     39                    const std::string& group,
     40                    std::set<GroupAndName>* to) {
     41   const std::vector<const Event*>* events = table->GetEventsByGroup(group);
     42   if (!events)
     43     return;
     44   for (const Event* event : *events)
     45     to->insert(GroupAndName(group, event->name));
     46 }
     47 
     48 std::set<GroupAndName> ReadEventsInGroupFromFs(
     49     const FtraceProcfs& ftrace_procfs,
     50     const std::string& group) {
     51   std::set<std::string> names =
     52       ftrace_procfs.GetEventNamesForGroup("events/" + group);
     53   std::set<GroupAndName> events;
     54   for (const auto& name : names)
     55     events.insert(GroupAndName(group, name));
     56   return events;
     57 }
     58 
     59 std::pair<std::string, std::string> EventToStringGroupAndName(
     60     const std::string& event) {
     61   auto slash_pos = event.find("/");
     62   if (slash_pos == std::string::npos)
     63     return std::make_pair("", event);
     64   return std::make_pair(event.substr(0, slash_pos),
     65                         event.substr(slash_pos + 1));
     66 }
     67 
     68 }  // namespace
     69 
     70 std::set<GroupAndName> FtraceConfigMuxer::GetFtraceEvents(
     71     const FtraceConfig& request,
     72     const ProtoTranslationTable* table) {
     73   std::set<GroupAndName> events;
     74   for (const auto& config_value : request.ftrace_events()) {
     75     std::string group;
     76     std::string name;
     77     std::tie(group, name) = EventToStringGroupAndName(config_value);
     78     if (name == "*") {
     79       for (const auto& event : ReadEventsInGroupFromFs(*ftrace_, group))
     80         events.insert(event);
     81     } else if (group.empty()) {
     82       // If there is no group specified, find an event with that name and
     83       // use it's group.
     84       const Event* e = table->GetEventByName(name);
     85       if (!e) {
     86         PERFETTO_DLOG(
     87             "Event doesn't exist: %s. Include the group in the config to allow "
     88             "the event to be output as a generic event.",
     89             name.c_str());
     90         continue;
     91       }
     92       events.insert(GroupAndName(e->group, e->name));
     93     } else {
     94       events.insert(GroupAndName(group, name));
     95     }
     96   }
     97   if (RequiresAtrace(request)) {
     98     events.insert(GroupAndName("ftrace", "print"));
     99 
    100     // Ideally we should keep this code in sync with:
    101     // platform/frameworks/native/cmds/atrace/atrace.cpp
    102     // It's not a disaster if they go out of sync, we can always add the ftrace
    103     // categories manually server side but this is user friendly and reduces the
    104     // size of the configs.
    105     for (const std::string& category : request.atrace_categories()) {
    106       if (category == "gfx") {
    107         AddEventGroup(table, "mdss", &events);
    108         AddEventGroup(table, "sde", &events);
    109         continue;
    110       }
    111 
    112       if (category == "ion") {
    113         events.insert(GroupAndName("kmem", "ion_alloc_buffer_start"));
    114         continue;
    115       }
    116 
    117       if (category == "sched") {
    118         events.insert(GroupAndName("sched", "sched_switch"));
    119         events.insert(GroupAndName("sched", "sched_wakeup"));
    120         events.insert(GroupAndName("sched", "sched_waking"));
    121         events.insert(GroupAndName("sched", "sched_blocked_reason"));
    122         events.insert(GroupAndName("sched", "sched_cpu_hotplug"));
    123         events.insert(GroupAndName("sched", "sched_pi_setprio"));
    124         events.insert(GroupAndName("sched", "sched_process_exit"));
    125         events.insert(GroupAndName("systrace", "0"));
    126         AddEventGroup(table, "cgroup", &events);
    127         events.insert(GroupAndName("oom", "oom_score_adj_update"));
    128         events.insert(GroupAndName("task", "task_rename"));
    129         events.insert(GroupAndName("task", "task_newtask"));
    130         AddEventGroup(table, "systrace", &events);
    131         AddEventGroup(table, "scm", &events);
    132         continue;
    133       }
    134 
    135       if (category == "irq") {
    136         AddEventGroup(table, "irq", &events);
    137         AddEventGroup(table, "ipi", &events);
    138         continue;
    139       }
    140 
    141       if (category == "irqoff") {
    142         events.insert(GroupAndName("preemptirq", "irq_enable"));
    143         events.insert(GroupAndName("preemptirq", "irq_disable"));
    144         continue;
    145       }
    146 
    147       if (category == "preemptoff") {
    148         events.insert(GroupAndName("preemptirq", "preempt_enable"));
    149         events.insert(GroupAndName("preemptirq", "preempt_disable"));
    150         continue;
    151       }
    152 
    153       if (category == "i2c") {
    154         AddEventGroup(table, "i2c", &events);
    155         events.insert(GroupAndName("i2c", "i2c_read"));
    156         events.insert(GroupAndName("i2c", "i2c_write"));
    157         events.insert(GroupAndName("i2c", "i2c_result"));
    158         events.insert(GroupAndName("i2c", "i2c_reply"));
    159         events.insert(GroupAndName("i2c", "smbus_read"));
    160         events.insert(GroupAndName("i2c", "smbus_write"));
    161         events.insert(GroupAndName("i2c", "smbus_result"));
    162         events.insert(GroupAndName("i2c", "smbus_reply"));
    163         continue;
    164       }
    165 
    166       if (category == "freq") {
    167         events.insert(GroupAndName("power", "cpu_frequency"));
    168         events.insert(GroupAndName("power", "gpu_frequency"));
    169         events.insert(GroupAndName("power", "clock_set_rate"));
    170         events.insert(GroupAndName("power", "clock_disable"));
    171         events.insert(GroupAndName("power", "clock_enable"));
    172         events.insert(GroupAndName("clk", "clk_set_rate"));
    173         events.insert(GroupAndName("clk", "clk_disable"));
    174         events.insert(GroupAndName("clk", "clk_enable"));
    175         events.insert(GroupAndName("power", "cpu_frequency_limits"));
    176         AddEventGroup(table, "msm_bus", &events);
    177         continue;
    178       }
    179 
    180       if (category == "membus") {
    181         AddEventGroup(table, "memory_bus", &events);
    182         continue;
    183       }
    184 
    185       if (category == "idle") {
    186         events.insert(GroupAndName("power", "cpu_idle"));
    187         continue;
    188       }
    189 
    190       if (category == "disk") {
    191         events.insert(GroupAndName("f2fs", "f2fs_sync_file_enter"));
    192         events.insert(GroupAndName("f2fs", "f2fs_sync_file_exit"));
    193         events.insert(GroupAndName("f2fs", "f2fs_write_begin"));
    194         events.insert(GroupAndName("f2fs", "f2fs_write_end"));
    195         events.insert(GroupAndName("ext4", "ext4_da_write_begin"));
    196         events.insert(GroupAndName("ext4", "ext4_da_write_end"));
    197         events.insert(GroupAndName("ext4", "ext4_sync_file_enter"));
    198         events.insert(GroupAndName("ext4", "ext4_sync_file_exit"));
    199         events.insert(GroupAndName("block", "block_rq_issue"));
    200         events.insert(GroupAndName("block", "block_rq_complete"));
    201         continue;
    202       }
    203 
    204       if (category == "mmc") {
    205         AddEventGroup(table, "mmc", &events);
    206         continue;
    207       }
    208 
    209       if (category == "load") {
    210         AddEventGroup(table, "cpufreq_interactive", &events);
    211         continue;
    212       }
    213 
    214       if (category == "sync") {
    215         // linux kernel < 4.9
    216         AddEventGroup(table, "sync", &events);
    217         // linux kernel == 4.9.x
    218         AddEventGroup(table, "fence", &events);
    219         // linux kernel > 4.9
    220         AddEventGroup(table, "dma_fence", &events);
    221         continue;
    222       }
    223 
    224       if (category == "workq") {
    225         AddEventGroup(table, "workqueue", &events);
    226         continue;
    227       }
    228 
    229       if (category == "memreclaim") {
    230         events.insert(GroupAndName("vmscan", "mm_vmscan_direct_reclaim_begin"));
    231         events.insert(GroupAndName("vmscan", "mm_vmscan_direct_reclaim_end"));
    232         events.insert(GroupAndName("vmscan", "mm_vmscan_kswapd_wake"));
    233         events.insert(GroupAndName("vmscan", "mm_vmscan_kswapd_sleep"));
    234         AddEventGroup(table, "lowmemorykiller", &events);
    235         continue;
    236       }
    237 
    238       if (category == "regulators") {
    239         AddEventGroup(table, "regulator", &events);
    240         continue;
    241       }
    242 
    243       if (category == "binder_driver") {
    244         events.insert(GroupAndName("binder", "binder_transaction"));
    245         events.insert(GroupAndName("binder", "binder_transaction_received"));
    246         events.insert(GroupAndName("binder", "binder_transaction_alloc_buf"));
    247         events.insert(GroupAndName("binder", "binder_set_priority"));
    248         continue;
    249       }
    250 
    251       if (category == "binder_lock") {
    252         events.insert(GroupAndName("binder", "binder_lock"));
    253         events.insert(GroupAndName("binder", "binder_locked"));
    254         events.insert(GroupAndName("binder", "binder_unlock"));
    255         continue;
    256       }
    257 
    258       if (category == "pagecache") {
    259         AddEventGroup(table, "filemap", &events);
    260         continue;
    261       }
    262 
    263       if (category == "memory") {
    264         events.insert(GroupAndName("kmem", "rss_stat"));
    265         events.insert(GroupAndName("kmem", "ion_heap_grow"));
    266         events.insert(GroupAndName("kmem", "ion_heap_shrink"));
    267         continue;
    268       }
    269     }
    270   }
    271   return events;
    272 }
    273 
    274 // Post-conditions:
    275 // 1. result >= 1 (should have at least one page per CPU)
    276 // 2. result * 4 < kMaxTotalBufferSizeKb
    277 // 3. If input is 0 output is a good default number.
    278 size_t ComputeCpuBufferSizeInPages(size_t requested_buffer_size_kb) {
    279   if (requested_buffer_size_kb == 0)
    280     requested_buffer_size_kb = kDefaultPerCpuBufferSizeKb;
    281   if (requested_buffer_size_kb > kMaxPerCpuBufferSizeKb) {
    282     PERFETTO_ELOG(
    283         "The requested ftrace buf size (%zu KB) is too big, capping to %d KB",
    284         requested_buffer_size_kb, kMaxPerCpuBufferSizeKb);
    285     requested_buffer_size_kb = kMaxPerCpuBufferSizeKb;
    286   }
    287 
    288   size_t pages = requested_buffer_size_kb / (base::kPageSize / 1024);
    289   if (pages == 0)
    290     return 1;
    291 
    292   return pages;
    293 }
    294 
    295 FtraceConfigMuxer::FtraceConfigMuxer(FtraceProcfs* ftrace,
    296                                      ProtoTranslationTable* table)
    297     : ftrace_(ftrace),
    298       table_(table),
    299       current_state_(),
    300       filters_(),
    301       configs_() {}
    302 FtraceConfigMuxer::~FtraceConfigMuxer() = default;
    303 
    304 FtraceConfigId FtraceConfigMuxer::SetupConfig(const FtraceConfig& request) {
    305   EventFilter filter;
    306   FtraceConfig actual;
    307   bool is_ftrace_enabled = ftrace_->IsTracingEnabled();
    308   if (configs_.empty()) {
    309     PERFETTO_DCHECK(active_configs_.empty());
    310     PERFETTO_DCHECK(!current_state_.tracing_on);
    311 
    312     // If someone outside of perfetto is using ftrace give up now.
    313     if (is_ftrace_enabled)
    314       return 0;
    315 
    316     // Setup ftrace, without starting it. Setting buffers can be quite slow
    317     // (up to hundreds of ms).
    318     SetupClock(request);
    319     SetupBufferSize(request);
    320   } else {
    321     // Did someone turn ftrace off behind our back? If so give up.
    322     if (!active_configs_.empty() && !is_ftrace_enabled)
    323       return 0;
    324   }
    325 
    326   std::set<GroupAndName> events = GetFtraceEvents(request, table_);
    327 
    328   if (RequiresAtrace(request))
    329     UpdateAtrace(request);
    330 
    331   for (const auto& group_and_name : events) {
    332     const Event* event = table_->GetOrCreateEvent(group_and_name);
    333     if (!event) {
    334       PERFETTO_DLOG("Can't enable %s, event not known",
    335                     group_and_name.ToString().c_str());
    336       continue;
    337     }
    338     if (current_state_.ftrace_events.IsEventEnabled(event->ftrace_event_id) ||
    339         std::string("ftrace") == event->group) {
    340       filter.AddEnabledEvent(event->ftrace_event_id);
    341       *actual.add_ftrace_events() = group_and_name.ToString();
    342       continue;
    343     }
    344     if (ftrace_->EnableEvent(event->group, event->name)) {
    345       current_state_.ftrace_events.AddEnabledEvent(event->ftrace_event_id);
    346       filter.AddEnabledEvent(event->ftrace_event_id);
    347       *actual.add_ftrace_events() = group_and_name.ToString();
    348     } else {
    349       PERFETTO_DPLOG("Failed to enable %s.", group_and_name.ToString().c_str());
    350     }
    351   }
    352 
    353   FtraceConfigId id = ++last_id_;
    354   configs_.emplace(id, std::move(actual));
    355   filters_.emplace(id, std::move(filter));
    356   return id;
    357 }
    358 
    359 bool FtraceConfigMuxer::ActivateConfig(FtraceConfigId id) {
    360   if (!id || configs_.count(id) == 0) {
    361     PERFETTO_DFATAL("Config not found");
    362     return false;
    363   }
    364 
    365   active_configs_.insert(id);
    366   if (active_configs_.size() > 1) {
    367     PERFETTO_DCHECK(current_state_.tracing_on);
    368     return true;  // We are not the first, ftrace is already enabled. All done.
    369   }
    370 
    371   PERFETTO_DCHECK(!current_state_.tracing_on);
    372   if (ftrace_->IsTracingEnabled()) {
    373     // If someone outside of perfetto is using ftrace give up now.
    374     return false;
    375   }
    376 
    377   ftrace_->EnableTracing();
    378   current_state_.tracing_on = true;
    379   return true;
    380 }
    381 
    382 bool FtraceConfigMuxer::RemoveConfig(FtraceConfigId config_id) {
    383   if (!config_id || !filters_.erase(config_id) || !configs_.erase(config_id))
    384     return false;
    385   EventFilter expected_ftrace_events;
    386   for (const auto& id_filter : filters_) {
    387     expected_ftrace_events.EnableEventsFrom(id_filter.second);
    388   }
    389 
    390   // Disable any events that are currently enabled, but are not in any configs
    391   // anymore.
    392   std::set<size_t> event_ids = current_state_.ftrace_events.GetEnabledEvents();
    393   for (size_t id : event_ids) {
    394     if (expected_ftrace_events.IsEventEnabled(id))
    395       continue;
    396     const Event* event = table_->GetEventById(id);
    397     // Any event that was enabled must exist.
    398     PERFETTO_DCHECK(event);
    399     if (ftrace_->DisableEvent(event->group, event->name))
    400       current_state_.ftrace_events.DisableEvent(event->ftrace_event_id);
    401   }
    402 
    403   // If there aren't any more active configs, disable ftrace.
    404   auto active_it = active_configs_.find(config_id);
    405   if (active_it != active_configs_.end()) {
    406     PERFETTO_DCHECK(current_state_.tracing_on);
    407     active_configs_.erase(active_it);
    408     if (active_configs_.empty()) {
    409       // This was the last active config, disable ftrace.
    410       ftrace_->DisableTracing();
    411       current_state_.tracing_on = false;
    412     }
    413   }
    414 
    415   // Even if we don't have any other active configs, we might still have idle
    416   // configs around. Tear down the rest of the ftrace config only if all
    417   // configs are removed.
    418   if (configs_.empty()) {
    419     ftrace_->SetCpuBufferSizeInPages(0);
    420     ftrace_->DisableAllEvents();
    421     ftrace_->ClearTrace();
    422     if (current_state_.atrace_on)
    423       DisableAtrace();
    424   }
    425 
    426   return true;
    427 }
    428 
    429 const FtraceConfig* FtraceConfigMuxer::GetConfigForTesting(FtraceConfigId id) {
    430   if (!configs_.count(id))
    431     return nullptr;
    432   return &configs_.at(id);
    433 }
    434 
    435 const EventFilter* FtraceConfigMuxer::GetEventFilter(FtraceConfigId id) {
    436   if (!filters_.count(id))
    437     return nullptr;
    438   return &filters_.at(id);
    439 }
    440 
    441 void FtraceConfigMuxer::SetupClock(const FtraceConfig&) {
    442   std::string current_clock = ftrace_->GetClock();
    443   std::set<std::string> clocks = ftrace_->AvailableClocks();
    444 
    445   for (size_t i = 0; i < base::ArraySize(kClocks); i++) {
    446     std::string clock = std::string(kClocks[i]);
    447     if (!clocks.count(clock))
    448       continue;
    449     if (current_clock == clock)
    450       break;
    451     ftrace_->SetClock(clock);
    452     break;
    453   }
    454 }
    455 
    456 void FtraceConfigMuxer::SetupBufferSize(const FtraceConfig& request) {
    457   size_t pages = ComputeCpuBufferSizeInPages(request.buffer_size_kb());
    458   ftrace_->SetCpuBufferSizeInPages(pages);
    459   current_state_.cpu_buffer_size_pages = pages;
    460 }
    461 
    462 void FtraceConfigMuxer::UpdateAtrace(const FtraceConfig& request) {
    463   PERFETTO_DLOG("Update atrace config...");
    464 
    465   std::vector<std::string> args;
    466   args.push_back("atrace");  // argv0 for exec()
    467   args.push_back("--async_start");
    468   args.push_back("--only_userspace");
    469   for (const auto& category : request.atrace_categories())
    470     args.push_back(category);
    471   if (!request.atrace_apps().empty()) {
    472     args.push_back("-a");
    473     std::string arg = "";
    474     for (const auto& app : request.atrace_apps()) {
    475       arg += app;
    476       if (app != request.atrace_apps().back())
    477         arg += ",";
    478     }
    479     args.push_back(arg);
    480   }
    481 
    482   if (RunAtrace(args))
    483     current_state_.atrace_on = true;
    484 
    485   PERFETTO_DLOG("...done");
    486 }
    487 
    488 void FtraceConfigMuxer::DisableAtrace() {
    489   PERFETTO_DCHECK(current_state_.atrace_on);
    490 
    491   PERFETTO_DLOG("Stop atrace...");
    492 
    493   if (RunAtrace({"atrace", "--async_stop", "--only_userspace"}))
    494     current_state_.atrace_on = false;
    495 
    496   PERFETTO_DLOG("...done");
    497 }
    498 
    499 }  // namespace perfetto
    500