| Teng Qin | ef9d83f | 2019-02-28 15:29:55 -0800 | [diff] [blame] | 1 | /* |
| 2 | * Copyright (c) Facebook, Inc. |
| 3 | * Licensed under the Apache License, Version 2.0 (the "License") |
| 4 | */ |
| 5 | |
| 6 | #include <algorithm> |
| 7 | #include <cerrno> |
| 8 | #include <chrono> |
| 9 | #include <cstdio> |
| 10 | #include <cstring> |
| 11 | #include <exception> |
| Teng Qin | ef9d83f | 2019-02-28 15:29:55 -0800 | [diff] [blame] | 12 | |
| 13 | #include <dirent.h> |
| 14 | #include <linux/elf.h> |
| 15 | #include <sys/stat.h> |
| 16 | #include <sys/types.h> |
| 17 | #include <unistd.h> |
| 18 | |
| 19 | #include "PyPerfLoggingHelper.h" |
| 20 | #include "PyPerfUtil.h" |
| 21 | #include "bcc_elf.h" |
| 22 | #include "bcc_proc.h" |
| 23 | #include "bcc_syms.h" |
| 24 | |
| 25 | namespace ebpf { |
| 26 | namespace pyperf { |
| 27 | |
| 28 | extern OffsetConfig kPy36OffsetConfig; |
| 29 | extern std::string PYPERF_BPF_PROGRAM; |
| 30 | |
| Teng Qin | ef9d83f | 2019-02-28 15:29:55 -0800 | [diff] [blame] | 31 | const static int kPerfBufSizePages = 32; |
| 32 | |
| 33 | const static std::string kPidCfgTableName("pid_config"); |
| 34 | const static std::string kProgsTableName("progs"); |
| 35 | const static std::string kSamplePerfBufName("events"); |
| 36 | |
| 37 | const static std::string kOnEventFuncName("on_event"); |
| 38 | |
| 39 | const static std::string kPythonStackFuncName("read_python_stack"); |
| 40 | const static std::string kPythonStackProgIdxFlag("-DPYTHON_STACK_PROG_IDX="); |
| 41 | const static int kPythonStackProgIdx = 0; |
| 42 | |
| 43 | const static std::string kNumCpusFlag("-DNUM_CPUS="); |
| 44 | const static std::string kSymbolsHashSizeFlag("-D__SYMBOLS_SIZE__="); |
| 45 | const static int kSymbolsHashSize = 16384; |
| 46 | |
| 47 | namespace { |
| 48 | |
| 49 | bool getRunningPids(std::vector<int>& output) { |
| 50 | auto dir = ::opendir("/proc/"); |
| 51 | if (!dir) { |
| 52 | std::fprintf(stderr, "Open /proc failed: %d\n", errno); |
| 53 | return false; |
| 54 | } |
| 55 | |
| 56 | dirent* result = nullptr; |
| 57 | do { |
| 58 | if ((result = readdir(dir))) { |
| 59 | std::string basename = result->d_name; |
| 60 | if (basename == "." || basename == "..") { |
| 61 | continue; |
| 62 | } |
| 63 | |
| 64 | std::string fullpath = "/proc/" + basename; |
| 65 | struct stat st; |
| 66 | if (::stat(fullpath.c_str(), &st) != 0 || !S_ISDIR(st.st_mode)) { |
| 67 | continue; |
| 68 | } |
| 69 | |
| 70 | try { |
| 71 | auto pid = std::stoi(basename); |
| 72 | output.push_back(pid); |
| 73 | } catch (const std::exception& e) { |
| 74 | continue; |
| 75 | } |
| 76 | } |
| 77 | } while (result); |
| 78 | |
| 79 | if (::closedir(dir) == -1) { |
| 80 | std::fprintf(stderr, "Close /proc failed: %d\n", errno); |
| 81 | return false; |
| 82 | } |
| 83 | |
| 84 | return true; |
| 85 | } |
| 86 | |
| 87 | typedef struct { |
| 88 | int pid; |
| 89 | bool found; |
| 90 | uint64_t st; |
| 91 | uint64_t en; |
| 92 | } FindPythonPathHelper; |
| 93 | |
| 94 | const static std::string kPy36LibName = "libpython3.6"; |
| 95 | |
| 96 | int findPythonPathCallback(const char* name, uint64_t st, uint64_t en, uint64_t, |
| 97 | bool, void* payload) { |
| 98 | auto helper = static_cast<FindPythonPathHelper*>(payload); |
| 99 | std::string file = name; |
| 100 | auto pos = file.rfind("/"); |
| 101 | if (pos != std::string::npos) { |
| 102 | file = file.substr(pos + 1); |
| 103 | } |
| 104 | if (file.find(kPy36LibName) == 0) { |
| Teng Qin | 873e939 | 2019-03-07 21:56:10 -0800 | [diff] [blame^] | 105 | logInfo(1, "Found Python library %s loaded at %lx-%lx for PID %d\n", name, |
| 106 | st, en, helper->pid); |
| Teng Qin | ef9d83f | 2019-02-28 15:29:55 -0800 | [diff] [blame] | 107 | helper->found = true; |
| 108 | helper->st = st; |
| 109 | helper->en = en; |
| 110 | return -1; |
| 111 | } |
| 112 | return 0; |
| 113 | } |
| 114 | |
| 115 | bool allAddrFound(const PidData& data) { |
| 116 | return (data.current_state_addr > 0) && (data.tls_key_addr > 0) && |
| 117 | (data.gil_locked_addr > 0) && (data.gil_last_holder_addr > 0); |
| 118 | } |
| 119 | |
| 120 | int getAddrOfPythonBinaryCallback(const char* name, uint64_t addr, uint64_t, |
| 121 | void* payload) { |
| 122 | PidData& data = *static_cast<PidData*>(payload); |
| 123 | |
| 124 | auto checkAndGetAddr = [&](uintptr_t& targetAddr, const char* targetName) { |
| 125 | if (targetAddr == 0 && std::strcmp(name, targetName) == 0) { |
| 126 | targetAddr = addr; |
| 127 | } |
| 128 | }; |
| 129 | |
| 130 | checkAndGetAddr(data.tls_key_addr, "autoTLSkey"); |
| 131 | checkAndGetAddr(data.current_state_addr, "_PyThreadState_Current"); |
| 132 | checkAndGetAddr(data.gil_locked_addr, "gil_locked"); |
| 133 | checkAndGetAddr(data.gil_last_holder_addr, "gil_last_holder"); |
| 134 | |
| 135 | if (allAddrFound(data)) { |
| 136 | return -1; |
| 137 | } |
| 138 | return 0; |
| 139 | } |
| 140 | |
| 141 | bool getAddrOfPythonBinary(const std::string& path, PidData& data) { |
| 142 | std::memset(&data, 0, sizeof(data)); |
| 143 | |
| 144 | struct bcc_symbol_option option = {.use_debug_file = 0, |
| 145 | .check_debug_file_crc = 0, |
| 146 | .use_symbol_type = (1 << STT_OBJECT)}; |
| 147 | |
| 148 | bcc_elf_foreach_sym(path.c_str(), &getAddrOfPythonBinaryCallback, &option, |
| 149 | &data); |
| 150 | |
| 151 | return allAddrFound(data); |
| 152 | } |
| 153 | } // namespace |
| 154 | |
| 155 | void handleSampleCallback(void* cb_cookie, void* raw_data, int data_size) { |
| 156 | auto profiler = static_cast<PyPerfUtil*>(cb_cookie); |
| 157 | profiler->handleSample(raw_data, data_size); |
| 158 | } |
| 159 | |
| 160 | void handleLostSamplesCallback(void* cb_cookie, uint64_t lost_cnt) { |
| 161 | auto profiler = static_cast<PyPerfUtil*>(cb_cookie); |
| 162 | profiler->handleLostSamples(lost_cnt); |
| 163 | } |
| 164 | |
| 165 | PyPerfUtil::PyPerfResult PyPerfUtil::init() { |
| 166 | std::vector<std::string> cflags; |
| 167 | cflags.emplace_back(kNumCpusFlag + |
| 168 | std::to_string(::sysconf(_SC_NPROCESSORS_ONLN))); |
| 169 | cflags.emplace_back(kSymbolsHashSizeFlag + std::to_string(kSymbolsHashSize)); |
| 170 | cflags.emplace_back(kPythonStackProgIdxFlag + |
| 171 | std::to_string(kPythonStackProgIdx)); |
| 172 | |
| 173 | auto initRes = bpf_.init(PYPERF_BPF_PROGRAM, cflags); |
| 174 | if (initRes.code() != 0) { |
| 175 | std::fprintf(stderr, "Failed to compiled PyPerf BPF programs: %s\n", |
| 176 | initRes.msg().c_str()); |
| 177 | return PyPerfResult::INIT_FAIL; |
| 178 | } |
| 179 | |
| 180 | int progFd = -1; |
| 181 | auto loadRes = |
| 182 | bpf_.load_func(kPythonStackFuncName, BPF_PROG_TYPE_PERF_EVENT, progFd); |
| 183 | if (loadRes.code() != 0) { |
| 184 | std::fprintf(stderr, "Failed to load BPF program %s: %s\n", |
| 185 | kPythonStackFuncName.c_str(), loadRes.msg().c_str()); |
| 186 | return PyPerfResult::INIT_FAIL; |
| 187 | } |
| 188 | |
| 189 | auto progTable = bpf_.get_prog_table(kProgsTableName); |
| 190 | auto updateRes = progTable.update_value(kPythonStackProgIdx, progFd); |
| 191 | if (updateRes.code() != 0) { |
| 192 | std::fprintf(stderr, |
| 193 | "Failed to set BPF program %s FD %d to program table: %s\n", |
| 194 | kPythonStackFuncName.c_str(), progFd, updateRes.msg().c_str()); |
| 195 | return PyPerfResult::INIT_FAIL; |
| 196 | } |
| 197 | |
| 198 | std::vector<int> pids; |
| 199 | if (!getRunningPids(pids)) { |
| 200 | std::fprintf(stderr, "Failed getting running Processes\n"); |
| 201 | return PyPerfResult::INIT_FAIL; |
| 202 | } |
| 203 | |
| 204 | // Populate config for each Python Process |
| 205 | auto pid_hash = bpf_.get_hash_table<int, PidData>(kPidCfgTableName); |
| 206 | PidData pidData; |
| 207 | for (const auto pid : pids) { |
| 208 | if (!tryTargetPid(pid, pidData)) { |
| 209 | // Not a Python Process |
| 210 | continue; |
| 211 | } |
| 212 | pid_hash.update_value(pid, pidData); |
| 213 | } |
| 214 | |
| 215 | // Open perf buffer |
| 216 | auto openRes = bpf_.open_perf_buffer( |
| 217 | kSamplePerfBufName, &handleSampleCallback, &handleLostSamplesCallback, |
| 218 | this, kPerfBufSizePages); |
| 219 | if (openRes.code() != 0) { |
| 220 | std::fprintf(stderr, "Unable to open Perf Buffer: %s\n", |
| 221 | openRes.msg().c_str()); |
| 222 | return PyPerfResult::PERF_BUF_OPEN_FAIL; |
| 223 | } |
| 224 | |
| 225 | initCompleted_ = true; |
| 226 | return PyPerfResult::SUCCESS; |
| 227 | } |
| 228 | |
| 229 | void PyPerfUtil::handleSample(const void* data, int dataSize) { |
| 230 | const Event* raw = static_cast<const Event*>(data); |
| 231 | samples_.emplace_back(raw, dataSize); |
| 232 | totalSamples_++; |
| 233 | } |
| 234 | |
| 235 | void PyPerfUtil::handleLostSamples(int lostCnt) { lostSamples_ += lostCnt; } |
| 236 | |
| 237 | PyPerfUtil::PyPerfResult PyPerfUtil::profile(int64_t sampleRate, |
| Teng Qin | 873e939 | 2019-03-07 21:56:10 -0800 | [diff] [blame^] | 238 | int64_t durationMs, |
| 239 | PyPerfSampleProcessor* processor) { |
| Teng Qin | ef9d83f | 2019-02-28 15:29:55 -0800 | [diff] [blame] | 240 | if (!initCompleted_) { |
| 241 | std::fprintf(stderr, "PyPerfUtil::init not invoked or failed\n"); |
| 242 | return PyPerfResult::NO_INIT; |
| 243 | } |
| 244 | |
| 245 | // Attach to CPU cycles |
| 246 | auto attachRes = |
| 247 | bpf_.attach_perf_event(0, 0, kOnEventFuncName, sampleRate, 0); |
| 248 | if (attachRes.code() != 0) { |
| 249 | std::fprintf(stderr, "Attach to CPU cycles event failed: %s\n", |
| 250 | attachRes.msg().c_str()); |
| 251 | return PyPerfResult::EVENT_ATTACH_FAIL; |
| 252 | } |
| 253 | logInfo(2, "Attached to profiling event\n"); |
| 254 | |
| 255 | // Get Perf Buffer and poll in a loop for a given duration |
| 256 | auto perfBuffer = bpf_.get_perf_buffer(kSamplePerfBufName); |
| 257 | if (!perfBuffer) { |
| 258 | std::fprintf(stderr, "Failed to get Perf Buffer: %s\n", |
| 259 | kSamplePerfBufName.c_str()); |
| 260 | return PyPerfResult::PERF_BUF_OPEN_FAIL; |
| 261 | } |
| 262 | logInfo(2, "Started polling Perf Buffer\n"); |
| 263 | auto start = std::chrono::steady_clock::now(); |
| 264 | while (std::chrono::steady_clock::now() < |
| 265 | start + std::chrono::milliseconds(durationMs)) { |
| 266 | perfBuffer->poll(50 /* 50ms timeout */); |
| 267 | } |
| 268 | logInfo(2, "Profiling duration finished\n"); |
| 269 | |
| 270 | // Detach the event |
| 271 | auto detachRes = bpf_.detach_perf_event(0, 0); |
| 272 | if (detachRes.code() != 0) { |
| 273 | std::fprintf(stderr, "Detach CPU cycles event failed: %s\n", |
| 274 | detachRes.msg().c_str()); |
| 275 | return PyPerfResult::EVENT_DETACH_FAIL; |
| 276 | } |
| 277 | logInfo(2, "Detached from profiling event\n"); |
| 278 | |
| 279 | // Drain remaining samples |
| 280 | logInfo(2, "Draining remaining samples\n"); |
| 281 | while (perfBuffer->poll(0) > 0) { |
| 282 | } |
| 283 | logInfo(2, "Finished draining remaining samples\n"); |
| 284 | |
| Teng Qin | 873e939 | 2019-03-07 21:56:10 -0800 | [diff] [blame^] | 285 | processor->processSamples(samples_, this); |
| 286 | |
| 287 | return PyPerfResult::SUCCESS; |
| 288 | } |
| 289 | |
| 290 | std::unordered_map<int32_t, std::string> PyPerfUtil::getSymbolMapping() { |
| Teng Qin | ef9d83f | 2019-02-28 15:29:55 -0800 | [diff] [blame] | 291 | auto symbolTable = bpf_.get_hash_table<Symbol, int32_t>("symbols"); |
| 292 | std::unordered_map<int32_t, std::string> symbols; |
| 293 | for (auto& x : symbolTable.get_table_offline()) { |
| 294 | auto symbolName = getSymbolName(x.first); |
| 295 | logInfo(2, "Symbol ID %d is %s\n", x.second, symbolName.c_str()); |
| 296 | symbols.emplace(x.second, std::move(symbolName)); |
| 297 | } |
| 298 | logInfo(1, "Total %d unique Python symbols\n", symbols.size()); |
| Teng Qin | 873e939 | 2019-03-07 21:56:10 -0800 | [diff] [blame^] | 299 | return symbols; |
| Teng Qin | ef9d83f | 2019-02-28 15:29:55 -0800 | [diff] [blame] | 300 | } |
| 301 | |
| 302 | std::string PyPerfUtil::getSymbolName(Symbol& sym) const { |
| 303 | std::string nameStr = std::string(sym.name).substr(0, FUNCTION_NAME_LEN); |
| 304 | std::string classStr = std::string(sym.classname).substr(0, CLASS_NAME_LEN); |
| 305 | if (classStr.size() > 0) { |
| 306 | nameStr = classStr + "." + nameStr; |
| 307 | } |
| 308 | |
| 309 | std::string file = std::string(sym.file).substr(0, FILE_NAME_LEN); |
| 310 | if (file.empty()) { |
| 311 | return nameStr; |
| 312 | } |
| 313 | if (file[0] == '/') { |
| 314 | file = file.substr(1); |
| 315 | } |
| 316 | if (file.find("./") == 0) { |
| 317 | file = file.substr(2); |
| 318 | } |
| 319 | if (file.find(".py", file.size() - 3) == (file.size() - 3)) { |
| 320 | file = file.substr(0, file.size() - 3); |
| 321 | } |
| 322 | std::replace(file.begin(), file.end(), '/', '.'); |
| 323 | |
| 324 | return file + "." + nameStr; |
| 325 | } |
| 326 | |
| 327 | bool PyPerfUtil::tryTargetPid(int pid, PidData& data) { |
| 328 | FindPythonPathHelper helper{pid, false, 0, 0}; |
| 329 | bcc_procutils_each_module(pid, &findPythonPathCallback, &helper); |
| 330 | if (!helper.found) { |
| 331 | logInfo(2, "PID %d does not contain Python library\n", pid); |
| 332 | return false; |
| 333 | } |
| 334 | |
| 335 | char path[256]; |
| 336 | int res = std::snprintf(path, sizeof(path), "/proc/%d/map_files/%lx-%lx", pid, |
| 337 | helper.st, helper.en); |
| 338 | if (res < 0 || size_t(res) >= sizeof(path)) { |
| 339 | return false; |
| 340 | } |
| 341 | |
| 342 | if (!getAddrOfPythonBinary(path, data)) { |
| Teng Qin | 873e939 | 2019-03-07 21:56:10 -0800 | [diff] [blame^] | 343 | std::fprintf( |
| 344 | stderr, |
| 345 | "Failed getting addresses in potential Python library in PID %d\n", |
| 346 | pid); |
| Teng Qin | ef9d83f | 2019-02-28 15:29:55 -0800 | [diff] [blame] | 347 | return false; |
| 348 | } |
| 349 | data.offsets = kPy36OffsetConfig; |
| 350 | data.current_state_addr += helper.st; |
| Teng Qin | 873e939 | 2019-03-07 21:56:10 -0800 | [diff] [blame^] | 351 | logInfo(2, "PID %d has _PyThreadState_Current at %lx\n", pid, |
| 352 | data.current_state_addr); |
| Teng Qin | ef9d83f | 2019-02-28 15:29:55 -0800 | [diff] [blame] | 353 | data.tls_key_addr += helper.st; |
| 354 | logInfo(2, "PID %d has autoTLSKey at %lx\n", pid, data.current_state_addr); |
| 355 | data.gil_locked_addr += helper.st; |
| 356 | logInfo(2, "PID %d has gil_locked at %lx\n", pid, data.current_state_addr); |
| 357 | data.gil_last_holder_addr += helper.st; |
| Teng Qin | 873e939 | 2019-03-07 21:56:10 -0800 | [diff] [blame^] | 358 | logInfo(2, "PID %d has gil_last_holder at %lx\n", pid, |
| 359 | data.current_state_addr); |
| Teng Qin | ef9d83f | 2019-02-28 15:29:55 -0800 | [diff] [blame] | 360 | |
| 361 | return true; |
| 362 | } |
| 363 | |
| 364 | } // namespace pyperf |
| 365 | } // namespace ebpf |