contrib/llvm/lib/ExecutionEngine/PerfJITEvents/PerfJITEventListener.cpp

   1 //===-- PerfJITEventListener.cpp - Tell Linux's perf about JITted code ----===//
   2 //
   3 //                     The LLVM Compiler Infrastructure
   4 //
   5 // This file is distributed under the University of Illinois Open Source
   6 // License. See LICENSE.TXT for details.
   7 //
   8 //===----------------------------------------------------------------------===//
   9 //
  10 // This file defines a JITEventListener object that tells perf about JITted
  11 // functions, including source line information.
  12 //
  13 // Documentation for perf jit integration is available at:
  14 // https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/tools/perf/Documentation/jitdump-specification.txt
  15 // https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/tools/perf/Documentation/jit-interface.txt
  16 //
  17 //===----------------------------------------------------------------------===//
  18
  19 #include "llvm/ADT/Twine.h"
  20 #include "llvm/Config/config.h"
  21 #include "llvm/DebugInfo/DWARF/DWARFContext.h"
  22 #include "llvm/ExecutionEngine/JITEventListener.h"
  23 #include "llvm/Object/ObjectFile.h"
  24 #include "llvm/Object/SymbolSize.h"
  25 #include "llvm/Support/Debug.h"
  26 #include "llvm/Support/Errno.h"
  27 #include "llvm/Support/FileSystem.h"
  28 #include "llvm/Support/MemoryBuffer.h"
  29 #include "llvm/Support/Mutex.h"
  30 #include "llvm/Support/MutexGuard.h"
  31 #include "llvm/Support/Path.h"
  32 #include "llvm/Support/Process.h"
  33 #include "llvm/Support/Threading.h"
  34 #include "llvm/Support/raw_ostream.h"
  35
  36 #include <sys/mman.h>  // mmap()
  37 #include <sys/types.h> // getpid()
  38 #include <time.h>      // clock_gettime(), time(), localtime_r() */
  39 #include <unistd.h>    // for getpid(), read(), close()
  40
  41 using namespace llvm;
  42 using namespace llvm::object;
  43 typedef DILineInfoSpecifier::FileLineInfoKind FileLineInfoKind;
  44
  45 namespace {
  46
  47 // language identifier (XXX: should we generate something better from debug
  48 // info?)
  49 #define JIT_LANG "llvm-IR"
  50 #define LLVM_PERF_JIT_MAGIC                                                    \
  51   ((uint32_t)'J' << 24 | (uint32_t)'i' << 16 | (uint32_t)'T' << 8 |            \
  52    (uint32_t)'D')
  53 #define LLVM_PERF_JIT_VERSION 1
  54
  55 // bit 0: set if the jitdump file is using an architecture-specific timestamp
  56 // clock source
  57 #define JITDUMP_FLAGS_ARCH_TIMESTAMP (1ULL << 0)
  58
  59 struct LLVMPerfJitHeader;
  60
  61 class PerfJITEventListener : public JITEventListener {
  62 public:
  63   PerfJITEventListener();
  64   ~PerfJITEventListener() {
  65     if (MarkerAddr)
  66       CloseMarker();
  67   }
  68
  69   void notifyObjectLoaded(ObjectKey K, const ObjectFile &Obj,
  70                           const RuntimeDyld::LoadedObjectInfo &L) override;
  71   void notifyFreeingObject(ObjectKey K) override;
  72
  73 private:
  74   bool InitDebuggingDir();
  75   bool OpenMarker();
  76   void CloseMarker();
  77   static bool FillMachine(LLVMPerfJitHeader &hdr);
  78
  79   void NotifyCode(Expected<llvm::StringRef> &Symbol, uint64_t CodeAddr,
  80                   uint64_t CodeSize);
  81   void NotifyDebug(uint64_t CodeAddr, DILineInfoTable Lines);
  82
  83   // cache lookups
  84   pid_t Pid;
  85
  86   // base directory for output data
  87   std::string JitPath;
  88
  89   // output data stream, closed via Dumpstream
  90   int DumpFd = -1;
  91
  92   // output data stream
  93   std::unique_ptr<raw_fd_ostream> Dumpstream;
  94
  95   // prevent concurrent dumps from messing up the output file
  96   sys::Mutex Mutex;
  97
  98   // perf mmap marker
  99   void *MarkerAddr = NULL;
 100
 101   // perf support ready
 102   bool SuccessfullyInitialized = false;
 103
 104   // identifier for functions, primarily to identify when moving them around
 105   uint64_t CodeGeneration = 1;
 106 };
 107
 108 // The following are POD struct definitions from the perf jit specification
 109
 110 enum LLVMPerfJitRecordType {
 111   JIT_CODE_LOAD = 0,
 112   JIT_CODE_MOVE = 1, // not emitted, code isn't moved
 113   JIT_CODE_DEBUG_INFO = 2,
 114   JIT_CODE_CLOSE = 3,          // not emitted, unnecessary
 115   JIT_CODE_UNWINDING_INFO = 4, // not emitted
 116
 117   JIT_CODE_MAX
 118 };
 119
 120 struct LLVMPerfJitHeader {
 121   uint32_t Magic;     // characters "JiTD"
 122   uint32_t Version;   // header version
 123   uint32_t TotalSize; // total size of header
 124   uint32_t ElfMach;   // elf mach target
 125   uint32_t Pad1;      // reserved
 126   uint32_t Pid;
 127   uint64_t Timestamp; // timestamp
 128   uint64_t Flags;     // flags
 129 };
 130
 131 // record prefix (mandatory in each record)
 132 struct LLVMPerfJitRecordPrefix {
 133   uint32_t Id; // record type identifier
 134   uint32_t TotalSize;
 135   uint64_t Timestamp;
 136 };
 137
 138 struct LLVMPerfJitRecordCodeLoad {
 139   LLVMPerfJitRecordPrefix Prefix;
 140
 141   uint32_t Pid;
 142   uint32_t Tid;
 143   uint64_t Vma;
 144   uint64_t CodeAddr;
 145   uint64_t CodeSize;
 146   uint64_t CodeIndex;
 147 };
 148
 149 struct LLVMPerfJitDebugEntry {
 150   uint64_t Addr;
 151   int Lineno;  // source line number starting at 1
 152   int Discrim; // column discriminator, 0 is default
 153   // followed by null terminated filename, \xff\0 if same as previous entry
 154 };
 155
 156 struct LLVMPerfJitRecordDebugInfo {
 157   LLVMPerfJitRecordPrefix Prefix;
 158
 159   uint64_t CodeAddr;
 160   uint64_t NrEntry;
 161   // followed by NrEntry LLVMPerfJitDebugEntry records
 162 };
 163
 164 static inline uint64_t timespec_to_ns(const struct timespec *ts) {
 165   const uint64_t NanoSecPerSec = 1000000000;
 166   return ((uint64_t)ts->tv_sec * NanoSecPerSec) + ts->tv_nsec;
 167 }
 168
 169 static inline uint64_t perf_get_timestamp(void) {
 170   struct timespec ts;
 171   int ret;
 172
 173   ret = clock_gettime(CLOCK_MONOTONIC, &ts);
 174   if (ret)
 175     return 0;
 176
 177   return timespec_to_ns(&ts);
 178 }
 179
 180 PerfJITEventListener::PerfJITEventListener() : Pid(::getpid()) {
 181   // check if clock-source is supported
 182   if (!perf_get_timestamp()) {
 183     errs() << "kernel does not support CLOCK_MONOTONIC\n";
 184     return;
 185   }
 186
 187   if (!InitDebuggingDir()) {
 188     errs() << "could not initialize debugging directory\n";
 189     return;
 190   }
 191
 192   std::string Filename;
 193   raw_string_ostream FilenameBuf(Filename);
 194   FilenameBuf << JitPath << "/jit-" << Pid << ".dump";
 195
 196   // Need to open ourselves, because we need to hand the FD to OpenMarker() and
 197   // raw_fd_ostream doesn't expose the FD.
 198   using sys::fs::openFileForWrite;
 199   if (auto EC =
 200           openFileForReadWrite(FilenameBuf.str(), DumpFd,
 201                                sys::fs::CD_CreateNew, sys::fs::OF_None)) {
 202     errs() << "could not open JIT dump file " << FilenameBuf.str() << ": "
 203            << EC.message() << "\n";
 204     return;
 205   }
 206
 207   Dumpstream = make_unique<raw_fd_ostream>(DumpFd, true);
 208
 209   LLVMPerfJitHeader Header = {0};
 210   if (!FillMachine(Header))
 211     return;
 212
 213   // signal this process emits JIT information
 214   if (!OpenMarker())
 215     return;
 216
 217   // emit dumpstream header
 218   Header.Magic = LLVM_PERF_JIT_MAGIC;
 219   Header.Version = LLVM_PERF_JIT_VERSION;
 220   Header.TotalSize = sizeof(Header);
 221   Header.Pid = Pid;
 222   Header.Timestamp = perf_get_timestamp();
 223   Dumpstream->write(reinterpret_cast<const char *>(&Header), sizeof(Header));
 224
 225   // Everything initialized, can do profiling now.
 226   if (!Dumpstream->has_error())
 227     SuccessfullyInitialized = true;
 228 }
 229
 230 void PerfJITEventListener::notifyObjectLoaded(
 231     ObjectKey K, const ObjectFile &Obj,
 232     const RuntimeDyld::LoadedObjectInfo &L) {
 233
 234   if (!SuccessfullyInitialized)
 235     return;
 236
 237   OwningBinary<ObjectFile> DebugObjOwner = L.getObjectForDebug(Obj);
 238   const ObjectFile &DebugObj = *DebugObjOwner.getBinary();
 239
 240   // Get the address of the object image for use as a unique identifier
 241   std::unique_ptr<DIContext> Context = DWARFContext::create(DebugObj);
 242
 243   // Use symbol info to iterate over functions in the object.
 244   for (const std::pair<SymbolRef, uint64_t> &P : computeSymbolSizes(DebugObj)) {
 245     SymbolRef Sym = P.first;
 246     std::string SourceFileName;
 247
 248     Expected<SymbolRef::Type> SymTypeOrErr = Sym.getType();
 249     if (!SymTypeOrErr) {
 250       // There's not much we can with errors here
 251       consumeError(SymTypeOrErr.takeError());
 252       continue;
 253     }
 254     SymbolRef::Type SymType = *SymTypeOrErr;
 255     if (SymType != SymbolRef::ST_Function)
 256       continue;
 257
 258     Expected<StringRef> Name = Sym.getName();
 259     if (!Name) {
 260       consumeError(Name.takeError());
 261       continue;
 262     }
 263
 264     Expected<uint64_t> AddrOrErr = Sym.getAddress();
 265     if (!AddrOrErr) {
 266       consumeError(AddrOrErr.takeError());
 267       continue;
 268     }
 269     uint64_t Addr = *AddrOrErr;
 270     uint64_t Size = P.second;
 271
 272     // According to spec debugging info has to come before loading the
 273     // corresonding code load.
 274     DILineInfoTable Lines = Context->getLineInfoForAddressRange(
 275         Addr, Size, FileLineInfoKind::AbsoluteFilePath);
 276
 277     NotifyDebug(Addr, Lines);
 278     NotifyCode(Name, Addr, Size);
 279   }
 280
 281   Dumpstream->flush();
 282 }
 283
 284 void PerfJITEventListener::notifyFreeingObject(ObjectKey K) {
 285   // perf currently doesn't have an interface for unloading. But munmap()ing the
 286   // code section does, so that's ok.
 287 }
 288
 289 bool PerfJITEventListener::InitDebuggingDir() {
 290   time_t Time;
 291   struct tm LocalTime;
 292   char TimeBuffer[sizeof("YYYYMMDD")];
 293   SmallString<64> Path;
 294
 295   // search for location to dump data to
 296   if (const char *BaseDir = getenv("JITDUMPDIR"))
 297     Path.append(BaseDir);
 298   else if (!sys::path::home_directory(Path))
 299     Path = ".";
 300
 301   // create debug directory
 302   Path += "/.debug/jit/";
 303   if (auto EC = sys::fs::create_directories(Path)) {
 304     errs() << "could not create jit cache directory " << Path << ": "
 305            << EC.message() << "\n";
 306     return false;
 307   }
 308
 309   // create unique directory for dump data related to this process
 310   time(&Time);
 311   localtime_r(&Time, &LocalTime);
 312   strftime(TimeBuffer, sizeof(TimeBuffer), "%Y%m%d", &LocalTime);
 313   Path += JIT_LANG "-jit-";
 314   Path += TimeBuffer;
 315
 316   SmallString<128> UniqueDebugDir;
 317
 318   using sys::fs::createUniqueDirectory;
 319   if (auto EC = createUniqueDirectory(Path, UniqueDebugDir)) {
 320     errs() << "could not create unique jit cache directory " << UniqueDebugDir
 321            << ": " << EC.message() << "\n";
 322     return false;
 323   }
 324
 325   JitPath = UniqueDebugDir.str();
 326
 327   return true;
 328 }
 329
 330 bool PerfJITEventListener::OpenMarker() {
 331   // We mmap the jitdump to create an MMAP RECORD in perf.data file.  The mmap
 332   // is captured either live (perf record running when we mmap) or in deferred
 333   // mode, via /proc/PID/maps. The MMAP record is used as a marker of a jitdump
 334   // file for more meta data info about the jitted code. Perf report/annotate
 335   // detect this special filename and process the jitdump file.
 336   //
 337   // Mapping must be PROT_EXEC to ensure it is captured by perf record
 338   // even when not using -d option.
 339   MarkerAddr = ::mmap(NULL, sys::Process::getPageSize(), PROT_READ | PROT_EXEC,
 340                       MAP_PRIVATE, DumpFd, 0);
 341
 342   if (MarkerAddr == MAP_FAILED) {
 343     errs() << "could not mmap JIT marker\n";
 344     return false;
 345   }
 346   return true;
 347 }
 348
 349 void PerfJITEventListener::CloseMarker() {
 350   if (!MarkerAddr)
 351     return;
 352
 353   munmap(MarkerAddr, sys::Process::getPageSize());
 354   MarkerAddr = nullptr;
 355 }
 356
 357 bool PerfJITEventListener::FillMachine(LLVMPerfJitHeader &hdr) {
 358   char id[16];
 359   struct {
 360     uint16_t e_type;
 361     uint16_t e_machine;
 362   } info;
 363
 364   size_t RequiredMemory = sizeof(id) + sizeof(info);
 365
 366   ErrorOr<std::unique_ptr<MemoryBuffer>> MB =
 367     MemoryBuffer::getFileSlice("/proc/self/exe",
 368                                RequiredMemory,
 369                                0);
 370
 371   // This'll not guarantee that enough data was actually read from the
 372   // underlying file. Instead the trailing part of the buffer would be
 373   // zeroed. Given the ELF signature check below that seems ok though,
 374   // it's unlikely that the file ends just after that, and the
 375   // consequence would just be that perf wouldn't recognize the
 376   // signature.
 377   if (auto EC = MB.getError()) {
 378     errs() << "could not open /proc/self/exe: " << EC.message() << "\n";
 379     return false;
 380   }
 381
 382   memcpy(&id, (*MB)->getBufferStart(), sizeof(id));
 383   memcpy(&info, (*MB)->getBufferStart() + sizeof(id), sizeof(info));
 384
 385   // check ELF signature
 386   if (id[0] != 0x7f || id[1] != 'E' || id[2] != 'L' || id[3] != 'F') {
 387     errs() << "invalid elf signature\n";
 388     return false;
 389   }
 390
 391   hdr.ElfMach = info.e_machine;
 392
 393   return true;
 394 }
 395
 396 void PerfJITEventListener::NotifyCode(Expected<llvm::StringRef> &Symbol,
 397                                       uint64_t CodeAddr, uint64_t CodeSize) {
 398   assert(SuccessfullyInitialized);
 399
 400   // 0 length functions can't have samples.
 401   if (CodeSize == 0)
 402     return;
 403
 404   LLVMPerfJitRecordCodeLoad rec;
 405   rec.Prefix.Id = JIT_CODE_LOAD;
 406   rec.Prefix.TotalSize = sizeof(rec) +        // debug record itself
 407                          Symbol->size() + 1 + // symbol name
 408                          CodeSize;            // and code
 409   rec.Prefix.Timestamp = perf_get_timestamp();
 410
 411   rec.CodeSize = CodeSize;
 412   rec.Vma = 0;
 413   rec.CodeAddr = CodeAddr;
 414   rec.Pid = Pid;
 415   rec.Tid = get_threadid();
 416
 417   // avoid interspersing output
 418   MutexGuard Guard(Mutex);
 419
 420   rec.CodeIndex = CodeGeneration++; // under lock!
 421
 422   Dumpstream->write(reinterpret_cast<const char *>(&rec), sizeof(rec));
 423   Dumpstream->write(Symbol->data(), Symbol->size() + 1);
 424   Dumpstream->write(reinterpret_cast<const char *>(CodeAddr), CodeSize);
 425 }
 426
 427 void PerfJITEventListener::NotifyDebug(uint64_t CodeAddr,
 428                                        DILineInfoTable Lines) {
 429   assert(SuccessfullyInitialized);
 430
 431   // Didn't get useful debug info.
 432   if (Lines.empty())
 433     return;
 434
 435   LLVMPerfJitRecordDebugInfo rec;
 436   rec.Prefix.Id = JIT_CODE_DEBUG_INFO;
 437   rec.Prefix.TotalSize = sizeof(rec); // will be increased further
 438   rec.Prefix.Timestamp = perf_get_timestamp();
 439   rec.CodeAddr = CodeAddr;
 440   rec.NrEntry = Lines.size();
 441
 442   // compute total size size of record (variable due to filenames)
 443   DILineInfoTable::iterator Begin = Lines.begin();
 444   DILineInfoTable::iterator End = Lines.end();
 445   for (DILineInfoTable::iterator It = Begin; It != End; ++It) {
 446     DILineInfo &line = It->second;
 447     rec.Prefix.TotalSize += sizeof(LLVMPerfJitDebugEntry);
 448     rec.Prefix.TotalSize += line.FileName.size() + 1;
 449   }
 450
 451   // The debug_entry describes the source line information. It is defined as
 452   // follows in order:
 453   // * uint64_t code_addr: address of function for which the debug information
 454   // is generated
 455   // * uint32_t line     : source file line number (starting at 1)
 456   // * uint32_t discrim  : column discriminator, 0 is default
 457   // * char name[n]      : source file name in ASCII, including null termination
 458
 459   // avoid interspersing output
 460   MutexGuard Guard(Mutex);
 461
 462   Dumpstream->write(reinterpret_cast<const char *>(&rec), sizeof(rec));
 463
 464   for (DILineInfoTable::iterator It = Begin; It != End; ++It) {
 465     LLVMPerfJitDebugEntry LineInfo;
 466     DILineInfo &Line = It->second;
 467
 468     LineInfo.Addr = It->first;
 469     // The function re-created by perf is preceded by a elf
 470     // header. Need to adjust for that, otherwise the results are
 471     // wrong.
 472     LineInfo.Addr += 0x40;
 473     LineInfo.Lineno = Line.Line;
 474     LineInfo.Discrim = Line.Discriminator;
 475
 476     Dumpstream->write(reinterpret_cast<const char *>(&LineInfo),
 477                       sizeof(LineInfo));
 478     Dumpstream->write(Line.FileName.c_str(), Line.FileName.size() + 1);
 479   }
 480 }
 481
 482 // There should be only a single event listener per process, otherwise perf gets
 483 // confused.
 484 llvm::ManagedStatic<PerfJITEventListener> PerfListener;
 485
 486 } // end anonymous namespace
 487
 488 namespace llvm {
 489 JITEventListener *JITEventListener::createPerfJITEventListener() {
 490   return &*PerfListener;
 491 }
 492
 493 } // namespace llvm
 494
 495 LLVMJITEventListenerRef LLVMCreatePerfJITEventListener(void)
 496 {
 497   return wrap(JITEventListener::createPerfJITEventListener());
 498 }