From b52ebeb604c4d70c4e4c78098c1fbf65f93a1c81 Mon Sep 17 00:00:00 2001 From: Christian von Elm Date: Wed, 15 Jan 2025 12:58:11 +0100 Subject: [PATCH] Add print_attr() Add a function for printing the perf_event_attr of Event's. This is incredibly useful for debugging. Printing out the perf_event_attr is triggered on event open and is only printed when the log level trace is specified Move pre-defined event table from global to function scope, so that the events in it do not get initialized before we set up logging. --- include/lo2s/perf/event.hpp | 3 + src/perf/event.cpp | 250 +++++++++++++++++++++++++++++++++++- src/perf/event_provider.cpp | 87 +++++++------ 3 files changed, 294 insertions(+), 46 deletions(-) diff --git a/include/lo2s/perf/event.hpp b/include/lo2s/perf/event.hpp index 2e8a385e..86b6d7ab 100644 --- a/include/lo2s/perf/event.hpp +++ b/include/lo2s/perf/event.hpp @@ -29,6 +29,7 @@ #include #include +#include #include #include #include @@ -149,6 +150,8 @@ class Event attr_.wakeup_watermark = static_cast(0.8 * mmap_pages * sysconf(_SC_PAGESIZE)); } + friend std::ostream& operator<<(std::ostream& stream, const Event& event); + void exclude_kernel(bool exclude_kernel) { attr_.exclude_kernel = exclude_kernel; diff --git a/src/perf/event.cpp b/src/perf/event.cpp index 5fb3305a..090b15a1 100644 --- a/src/perf/event.cpp +++ b/src/perf/event.cpp @@ -19,6 +19,7 @@ * along with lo2s. If not, see . */ +#include #include #include @@ -32,6 +33,7 @@ extern "C" { #include +#include #include } @@ -348,6 +350,246 @@ bool Event::degrade_precision() } } +static void print_bits(std::ostream& stream, const std::string& name, + std::map known_bits, uint64_t value) +{ + std::vector active_bits; + for (auto elem : known_bits) + { + if (value & elem.first) + { + active_bits.push_back(elem.second); + value &= ~elem.first; + } + } + + if (value != 0) + { + stream << "Unknown perf_event_attr." << name << " bits: " << std::hex << value << std::dec; + } + + std::string active_bits_str; + if (!active_bits.empty()) + { + auto it = active_bits.begin(); + for (; it != --active_bits.end(); it++) + { + active_bits_str += *it; + active_bits_str += " | "; + } + active_bits_str += *it; + } + stream << "\t" << name << ": " << active_bits_str << "\n"; +} + +std::ostream& operator<<(std::ostream& stream, const Event& event) +{ + stream << "{\n"; + switch (event.attr_.type) + { + case PERF_TYPE_HARDWARE: + stream << "\ttype: PERF_TYPE_HARDWARE\n"; + break; + case PERF_TYPE_SOFTWARE: + stream << "\ttype: PERF_TYPE_SOFTWARE\n"; + break; + case PERF_TYPE_TRACEPOINT: + stream << "\ttype: PERF_TYPE_TRACEPOINT\n"; + break; + case PERF_TYPE_HW_CACHE: + stream << "\ttype: PERF_TYPE_HW_CACHE\n"; + break; + case PERF_TYPE_RAW: + stream << "\ttype: PERF_TYPE_RAW\n"; + break; + case PERF_TYPE_BREAKPOINT: + stream << "\ttype: PERF_TYPE_BREAKPOINT\n"; + break; + default: + stream << "\ttype: " << std::hex << event.attr_.type << std::dec << "\n"; + } + stream << "\tsize: " << event.attr_.size << "\n"; + stream << std::hex << "\tconfig: 0x" << event.attr_.config << std::dec << "\n"; + stream << std::hex << "\tconfig1: 0x" << event.attr_.config1 << std::dec << "\n"; + stream << std::hex << "\tconfig2: 0x" << event.attr_.config2 << std::dec << "\n"; + stream << "\tprecise_ip: " << event.attr_.precise_ip << "/3\n"; + + std::map read_format = { + { PERF_FORMAT_TOTAL_TIME_ENABLED, "PERF_FORMAT_TOTAL_TIME_ENABLED" }, + { PERF_FORMAT_TOTAL_TIME_RUNNING, "PERF_FORMAT_TOTAL_TIME_RUNNING" }, + { PERF_FORMAT_ID, "PERF_FORMAT_ID" }, + { PERF_FORMAT_GROUP, "PERF_FORMAT_GROUP" }, + { PERF_FORMAT_LOST, "PERF_FORMAT_LOST" } + }; + + print_bits(stream, "read_format", read_format, event.attr_.read_format); + +#ifndef USE_HW_BREAKPOINT_COMPAT + if (event.attr_.type == PERF_TYPE_BREAKPOINT) + { + std::map bp_types = { { HW_BREAKPOINT_EMPTY, "HW_BREAKPOINT_EMPTY" }, + { HW_BREAKPOINT_W, "HW_BREAKPOINT_W" }, + { HW_BREAKPOINT_R, "HW_BREAKPOINT_R" }, + { HW_BREAKPOINT_RW, "HW_BREAKPOINT_RW" }, + { HW_BREAKPOINT_X, "HW_BREAKPOINT_X" } }; + + print_bits(stream, "bp_type", bp_types, event.attr_.bp_type); + stream << "\tbp_addr: 0x" << std::hex << event.attr_.bp_addr << std::dec << "\n"; + switch (event.attr_.bp_len) + { + case HW_BREAKPOINT_LEN_1: + stream << "\tbp_len: HW_BREAKPOINT_LEN_1\n"; + break; + case HW_BREAKPOINT_LEN_2: + stream << "\tbp_len: HW_BREAKPOINT_LEN_2\n"; + break; + case HW_BREAKPOINT_LEN_4: + stream << "\tbp_len: HW_BREAKPOINT_LEN_4\n"; + break; + case HW_BREAKPOINT_LEN_8: + stream << "\tbp_len: HW_BREAKPOINT_LEN_8\n"; + break; + } + } +#endif + if (event.attr_.freq) + { + stream << "\tsample_freq: " << event.attr_.sample_freq << " Hz\n"; + } + else + { + stream << "\tsample_period: " << event.attr_.sample_period << " event(s)\n"; + } + + std::map sample_format = { + { PERF_SAMPLE_CALLCHAIN, "PERF_SAMPLE_CALLCHAIN" }, + { PERF_SAMPLE_READ, "PERF_SAMPLE_READ" }, + { PERF_SAMPLE_IP, "PERF_SAMPLE_IP" }, + { PERF_SAMPLE_TID, "PERF_SAMPLE_TID" }, + { PERF_SAMPLE_CPU, "PERF_SAMPLE_CPU" }, + { PERF_SAMPLE_TIME, "PERF_SAMPLE_TIME" }, + { PERF_SAMPLE_RAW, "PERF_SAMPLE_RAW" }, + { PERF_SAMPLE_IDENTIFIER, "PERF_SAMPLE_IDENTIFIER" } + }; + + print_bits(stream, "sample_type", sample_format, event.attr_.sample_type); + + stream << "\tFLAGS: \n"; + if (event.attr_.disabled) + { + stream << "\t\t- disabled\n"; + } + if (event.attr_.pinned) + { + stream << "\t\t- pinned\n"; + } + if (event.attr_.exclusive) + { + stream << "\t\t- exclusive\n"; + } + if (event.attr_.exclude_kernel) + { + stream << "\t\t- exclude_kernel\n"; + } + if (event.attr_.exclude_user) + { + stream << "\t\t- exclude_user\n"; + } + if (event.attr_.exclude_hv) + { + stream << "\t\t- exclude_hv\n"; + } + if (event.attr_.exclude_idle) + { + stream << "\t\t- exclude_idle\n"; + } + if (event.attr_.mmap) + { + stream << "\t\t- mmap\n"; + } + if (event.attr_.inherit_stat) + { + stream << "\t\t- inherit_stat\n"; + } + if (event.attr_.enable_on_exec) + { + stream << "\t\t- enable_on_exec\n"; + } + if (event.attr_.task) + { + stream << "\t\t- task\n"; + } + if (event.attr_.watermark) + { + stream << "\t\t- wakeup_watermark (" << event.attr_.wakeup_watermark << " bytes)" + << "\n"; + } + else + { + + stream << "\t\t- wakeup_events (" << event.attr_.wakeup_events << " events)\n"; + } + if (event.attr_.mmap_data) + { + stream << "\t\t- mmap_data\n"; + } + if (event.attr_.sample_id_all) + { + stream << "\t\t- sample_id_all\n"; + } + if (event.attr_.mmap2) + { + stream << "\t\t- mmap2\n"; + } + if (event.attr_.context_switch) + { + stream << "\t\t- context_switch\n"; + } + if (event.attr_.comm_exec) + { + stream << "\t\t- comm_exec\n"; + } + if (event.attr_.comm) + { + stream << "\t\t- comm\n"; + } + + if (event.attr_.comm_exec) + { + stream << "\t\t- comm_exec\n"; + } + if (event.attr_.use_clockid) + { + std::string clock; + switch (event.attr_.clockid) + { + case CLOCK_MONOTONIC: + clock = "monotonic"; + break; + case CLOCK_MONOTONIC_RAW: + clock = "monotonic-raw"; + break; + case CLOCK_REALTIME: + clock = "realtime"; + break; + case CLOCK_BOOTTIME: + clock = "boottime"; + break; + case CLOCK_TAI: + clock = "tai"; + break; + default: + stream << "Unknown clockid: " << event.attr_.clockid << "\n"; + clock = "???"; + break; + } + stream << "\t\t- clockid (" << clock << ")\n"; + } + + stream << "}\n"; + return stream; +} + SysfsEvent::SysfsEvent(const std::string& ev_name, bool enable_on_exec) : Event(ev_name, static_cast(0), 0) { @@ -557,22 +799,26 @@ EventGuard EventGuard::open_child(Event child, ExecutionScope location, int cgro EventGuard::EventGuard(Event& ev, std::variant location, int group_fd, int cgroup_fd) : fd_(-1) { - // can be deleted when scope gets replaced ExecutionScope scope; std::visit([&scope](auto loc) { scope = loc.as_scope(); }, location); + Log::trace() << "Opening perf event: " << ev.name() << "[" << scope.name() + << ",group fd: " << group_fd << ", cgroup fd: " << cgroup_fd << "]"; + Log::trace() << ev; fd_ = perf_event_open(&ev.mut_attr(), scope, group_fd, 0, cgroup_fd); if (fd_ < 0) { + Log::trace() << "Couldn't open event!: " << strerror(errno); throw_errno(); } if (fcntl(fd_, F_SETFL, O_NONBLOCK)) { - Log::error() << errno; + Log::trace() << "Couldn't set event nonblocking: " << strerror(errno); throw_errno(); } + Log::trace() << "Succesfully opened perf event! fd: " << fd_; } void EventGuard::enable() diff --git a/src/perf/event_provider.cpp b/src/perf/event_provider.cpp index 43eb8b11..5f2befaa 100644 --- a/src/perf/event_provider.cpp +++ b/src/perf/event_provider.cpp @@ -58,50 +58,6 @@ namespace #define PERF_EVENT_HW(name, id) PERF_EVENT(name, PERF_TYPE_HARDWARE, PERF_COUNT_HW_##id) #define PERF_EVENT_SW(name, id) PERF_EVENT(name, PERF_TYPE_SOFTWARE, PERF_COUNT_SW_##id) -static lo2s::perf::Event HW_EVENT_TABLE[] = { - PERF_EVENT_HW("cpu-cycles", CPU_CYCLES), - PERF_EVENT_HW("instructions", INSTRUCTIONS), - PERF_EVENT_HW("cache-references", CACHE_REFERENCES), - PERF_EVENT_HW("cache-misses", CACHE_MISSES), - PERF_EVENT_HW("branch-instructions", BRANCH_INSTRUCTIONS), - PERF_EVENT_HW("branch-misses", BRANCH_MISSES), - PERF_EVENT_HW("bus-cycles", BUS_CYCLES), -#ifdef HAVE_PERF_EVENT_STALLED_CYCLES_FRONTEND - PERF_EVENT_HW("stalled-cycles-frontend", STALLED_CYCLES_FRONTEND), -#endif -#ifdef HAVE_PERF_EVENT_STALLED_CYCLES_BACKEND - PERF_EVENT_HW("stalled-cycles-backend", STALLED_CYCLES_BACKEND), -#endif -#ifdef HAVE_PERF_EVENT_REF_CYCLES - PERF_EVENT_HW("ref-cycles", REF_CPU_CYCLES), -#endif -}; - -static lo2s::perf::Event SW_EVENT_TABLE[] = { - PERF_EVENT_SW("cpu-clock", CPU_CLOCK), - PERF_EVENT_SW("task-clock", TASK_CLOCK), - PERF_EVENT_SW("page-faults", PAGE_FAULTS), - PERF_EVENT_SW("context-switches", CONTEXT_SWITCHES), - PERF_EVENT_SW("cpu-migrations", CPU_MIGRATIONS), - PERF_EVENT_SW("minor-faults", PAGE_FAULTS_MIN), - PERF_EVENT_SW("major-faults", PAGE_FAULTS_MAJ), -#ifdef HAVE_PERF_EVENT_ALIGNMENT_FAULTS - PERF_EVENT_SW("alignment-faults", ALIGNMENT_FAULTS), -#endif -#ifdef HAVE_PERF_EVENT_EMULATION_FAULTS - PERF_EVENT_SW("emulation-faults", EMULATION_FAULTS), -#endif -#ifdef HAVE_PERF_EVENT_DUMMY - PERF_EVENT_SW("dummy", DUMMY), -#endif -#ifdef HAVE_PERF_EVENT_BPF_OUTPUT - PERF_EVENT_SW("bpf-output", BPF_OUTPUT), -#endif -#ifdef HAVE_PERF_EVENT_CGROUP_SWITCHES - PERF_EVENT_SW("cgroup-switches", CGROUP_SWITCHES), -#endif -}; - #define PERF_MAKE_CACHE_ID(id) (id) #define PERF_MAKE_CACHE_OP_ID(id) ((id) << 8) #define PERF_MAKE_CACHE_OP_RES_ID(id) ((id) << 16) @@ -158,6 +114,49 @@ namespace perf static void populate_event_map(std::unordered_map& map) { Log::info() << "checking available events..."; + lo2s::perf::Event HW_EVENT_TABLE[] = { + PERF_EVENT_HW("cpu-cycles", CPU_CYCLES), + PERF_EVENT_HW("instructions", INSTRUCTIONS), + PERF_EVENT_HW("cache-references", CACHE_REFERENCES), + PERF_EVENT_HW("cache-misses", CACHE_MISSES), + PERF_EVENT_HW("branch-instructions", BRANCH_INSTRUCTIONS), + PERF_EVENT_HW("branch-misses", BRANCH_MISSES), + PERF_EVENT_HW("bus-cycles", BUS_CYCLES), +#ifdef HAVE_PERF_EVENT_STALLED_CYCLES_FRONTEND + PERF_EVENT_HW("stalled-cycles-frontend", STALLED_CYCLES_FRONTEND), +#endif +#ifdef HAVE_PERF_EVENT_STALLED_CYCLES_BACKEND + PERF_EVENT_HW("stalled-cycles-backend", STALLED_CYCLES_BACKEND), +#endif +#ifdef HAVE_PERF_EVENT_REF_CYCLES + PERF_EVENT_HW("ref-cycles", REF_CPU_CYCLES), +#endif + }; + lo2s::perf::Event SW_EVENT_TABLE[] = { + PERF_EVENT_SW("cpu-clock", CPU_CLOCK), + PERF_EVENT_SW("task-clock", TASK_CLOCK), + PERF_EVENT_SW("page-faults", PAGE_FAULTS), + PERF_EVENT_SW("context-switches", CONTEXT_SWITCHES), + PERF_EVENT_SW("cpu-migrations", CPU_MIGRATIONS), + PERF_EVENT_SW("minor-faults", PAGE_FAULTS_MIN), + PERF_EVENT_SW("major-faults", PAGE_FAULTS_MAJ), +#ifdef HAVE_PERF_EVENT_ALIGNMENT_FAULTS + PERF_EVENT_SW("alignment-faults", ALIGNMENT_FAULTS), +#endif +#ifdef HAVE_PERF_EVENT_EMULATION_FAULTS + PERF_EVENT_SW("emulation-faults", EMULATION_FAULTS), +#endif +#ifdef HAVE_PERF_EVENT_DUMMY + PERF_EVENT_SW("dummy", DUMMY), +#endif +#ifdef HAVE_PERF_EVENT_BPF_OUTPUT + PERF_EVENT_SW("bpf-output", BPF_OUTPUT), +#endif +#ifdef HAVE_PERF_EVENT_CGROUP_SWITCHES + PERF_EVENT_SW("cgroup-switches", CGROUP_SWITCHES), +#endif + }; + map.reserve(array_size(HW_EVENT_TABLE) + array_size(SW_EVENT_TABLE) + array_size(CACHE_NAME_TABLE) * array_size(CACHE_OPERATION_TABLE)); for (auto& ev : HW_EVENT_TABLE)