perf-jit.cc 16.1 KB
Newer Older
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29
// Copyright 2016 the V8 project authors. All rights reserved.
// Redistribution and use in source and binary forms, with or without
// modification, are permitted provided that the following conditions are
// met:
//
//     * Redistributions of source code must retain the above copyright
//       notice, this list of conditions and the following disclaimer.
//     * Redistributions in binary form must reproduce the above
//       copyright notice, this list of conditions and the following
//       disclaimer in the documentation and/or other materials provided
//       with the distribution.
//     * Neither the name of Google Inc. nor the names of its
//       contributors may be used to endorse or promote products derived
//       from this software without specific prior written permission.
//
// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.

#include "src/perf-jit.h"

30 31
#include <memory>

32
#include "src/assembler.h"
33
#include "src/eh-frame.h"
34
#include "src/objects-inl.h"
35
#include "src/ostreams.h"
36
#include "src/snapshot/embedded-data.h"
37
#include "src/source-position-table.h"
38
#include "src/wasm/wasm-code-manager.h"
39 40 41 42

#if V8_OS_LINUX
#include <fcntl.h>
#include <sys/mman.h>
43
#undef MAP_TYPE  // jumbo: conflicts with v8::internal::InstanceType::MAP_TYPE
44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66
#include <unistd.h>
#endif  // V8_OS_LINUX

namespace v8 {
namespace internal {

#if V8_OS_LINUX

struct PerfJitHeader {
  uint32_t magic_;
  uint32_t version_;
  uint32_t size_;
  uint32_t elf_mach_target_;
  uint32_t reserved_;
  uint32_t process_id_;
  uint64_t time_stamp_;
  uint64_t flags_;

  static const uint32_t kMagic = 0x4A695444;
  static const uint32_t kVersion = 1;
};

struct PerfJitBase {
67 68 69 70 71 72 73
  enum PerfJitEvent {
    kLoad = 0,
    kMove = 1,
    kDebugInfo = 2,
    kClose = 3,
    kUnwindingInfo = 4
  };
74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92

  uint32_t event_;
  uint32_t size_;
  uint64_t time_stamp_;
};

struct PerfJitCodeLoad : PerfJitBase {
  uint32_t process_id_;
  uint32_t thread_id_;
  uint64_t vma_;
  uint64_t code_address_;
  uint64_t code_size_;
  uint64_t code_id_;
};

struct PerfJitDebugEntry {
  uint64_t address_;
  int line_number_;
  int column_;
93
  // Followed by null-terminated name or \0xFF\0 if same as previous.
94 95 96 97 98 99 100 101
};

struct PerfJitCodeDebugInfo : PerfJitBase {
  uint64_t address_;
  uint64_t entry_count_;
  // Followed by entry_count_ instances of PerfJitDebugEntry.
};

102 103 104 105 106 107 108
struct PerfJitCodeUnwindingInfo : PerfJitBase {
  uint64_t unwinding_size_;
  uint64_t eh_frame_hdr_size_;
  uint64_t mapped_size_;
  // Followed by size_ - sizeof(PerfJitCodeUnwindingInfo) bytes of data.
};

109 110 111 112 113
const char PerfJitLogger::kFilenameFormatString[] = "./jit-%d.dump";

// Extra padding for the PID in the filename
const int PerfJitLogger::kFilenameBufferPadding = 16;

114 115 116 117 118 119 120
base::LazyRecursiveMutex PerfJitLogger::file_mutex_;
// The following static variables are protected by PerfJitLogger::file_mutex_.
uint64_t PerfJitLogger::reference_count_ = 0;
void* PerfJitLogger::marker_address_ = nullptr;
uint64_t PerfJitLogger::code_index_ = 0;
FILE* PerfJitLogger::perf_output_handle_ = nullptr;

121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139
void PerfJitLogger::OpenJitDumpFile() {
  // Open the perf JIT dump file.
  perf_output_handle_ = nullptr;

  int bufferSize = sizeof(kFilenameFormatString) + kFilenameBufferPadding;
  ScopedVector<char> perf_dump_name(bufferSize);
  int size = SNPrintF(perf_dump_name, kFilenameFormatString,
                      base::OS::GetCurrentProcessId());
  CHECK_NE(size, -1);

  int fd = open(perf_dump_name.start(), O_CREAT | O_TRUNC | O_RDWR, 0666);
  if (fd == -1) return;

  marker_address_ = OpenMarkerFile(fd);
  if (marker_address_ == nullptr) return;

  perf_output_handle_ = fdopen(fd, "w+");
  if (perf_output_handle_ == nullptr) return;

140
  setvbuf(perf_output_handle_, nullptr, _IOFBF, kLogBufferSize);
141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167
}

void PerfJitLogger::CloseJitDumpFile() {
  if (perf_output_handle_ == nullptr) return;
  fclose(perf_output_handle_);
  perf_output_handle_ = nullptr;
}

void* PerfJitLogger::OpenMarkerFile(int fd) {
  long page_size = sysconf(_SC_PAGESIZE);  // NOLINT(runtime/int)
  if (page_size == -1) return nullptr;

  // Mmap the file so that there is a mmap record in the perf_data file.
  //
  // The map must be PROT_EXEC to ensure it is not ignored by perf record.
  void* marker_address =
      mmap(nullptr, page_size, PROT_READ | PROT_EXEC, MAP_PRIVATE, fd, 0);
  return (marker_address == MAP_FAILED) ? nullptr : marker_address;
}

void PerfJitLogger::CloseMarkerFile(void* marker_address) {
  if (marker_address == nullptr) return;
  long page_size = sysconf(_SC_PAGESIZE);  // NOLINT(runtime/int)
  if (page_size == -1) return;
  munmap(marker_address, page_size);
}

168
PerfJitLogger::PerfJitLogger(Isolate* isolate) : CodeEventLogger(isolate) {
169 170 171 172 173 174 175 176 177
  base::LockGuard<base::RecursiveMutex> guard_file(file_mutex_.Pointer());

  reference_count_++;
  // If this is the first logger, open the file and write the header.
  if (reference_count_ == 1) {
    OpenJitDumpFile();
    if (perf_output_handle_ == nullptr) return;
    LogWriteHeader();
  }
178 179
}

180 181 182 183 184 185 186 187 188
PerfJitLogger::~PerfJitLogger() {
  base::LockGuard<base::RecursiveMutex> guard_file(file_mutex_.Pointer());

  reference_count_--;
  // If this was the last logger, close the file.
  if (reference_count_ == 0) {
    CloseJitDumpFile();
  }
}
189 190 191 192 193 194 195 196 197 198

uint64_t PerfJitLogger::GetTimestamp() {
  struct timespec ts;
  int result = clock_gettime(CLOCK_MONOTONIC, &ts);
  DCHECK_EQ(0, result);
  USE(result);
  static const uint64_t kNsecPerSec = 1000000000;
  return (ts.tv_sec * kNsecPerSec) + ts.tv_nsec;
}

199
void PerfJitLogger::LogRecordedBuffer(AbstractCode abstract_code,
200
                                      SharedFunctionInfo shared,
201 202
                                      const char* name, int length) {
  if (FLAG_perf_basic_prof_only_functions &&
203
      (abstract_code->kind() != AbstractCode::INTERPRETED_FUNCTION &&
204 205 206 207
       abstract_code->kind() != AbstractCode::OPTIMIZED_FUNCTION)) {
    return;
  }

208 209 210 211
  base::LockGuard<base::RecursiveMutex> guard_file(file_mutex_.Pointer());

  if (perf_output_handle_ == nullptr) return;

212 213
  // We only support non-interpreted functions.
  if (!abstract_code->IsCode()) return;
214
  Code code = abstract_code->GetCode();
215
  DCHECK(code->raw_instruction_start() == code->address() + Code::kHeaderSize);
216

217
  // Debug info has to be emitted first.
218
  if (FLAG_perf_prof && !shared.is_null()) {
219 220 221 222 223
    // TODO(herhut): This currently breaks for js2wasm/wasm2js functions.
    if (code->kind() != Code::JS_TO_WASM_FUNCTION &&
        code->kind() != Code::WASM_TO_JS_FUNCTION) {
      LogWriteDebugInfo(code, shared);
    }
224 225
  }

226
  const char* code_name = name;
227
  uint8_t* code_pointer = reinterpret_cast<uint8_t*>(code->InstructionStart());
228

229 230
  // Code generated by Turbofan will have the safepoint table directly after
  // instructions. There is no need to record the safepoint table itself.
231
  uint32_t code_size = code->ExecutableInstructionSize();
232

233 234 235
  // Unwinding info comes right after debug info.
  if (FLAG_perf_prof_unwinding_info) LogWriteUnwindingInfo(code);

236 237 238
  WriteJitCodeLoadEntry(code_pointer, code_size, code_name, length);
}

239 240
void PerfJitLogger::LogRecordedBuffer(const wasm::WasmCode* code,
                                      const char* name, int length) {
241 242 243 244 245 246 247 248 249 250 251
  base::LockGuard<base::RecursiveMutex> guard_file(file_mutex_.Pointer());

  if (perf_output_handle_ == nullptr) return;

  WriteJitCodeLoadEntry(code->instructions().start(),
                        code->instructions().length(), name, length);
}

void PerfJitLogger::WriteJitCodeLoadEntry(const uint8_t* code_pointer,
                                          uint32_t code_size, const char* name,
                                          int name_length) {
252
  static const char string_terminator[] = "\0";
253 254 255

  PerfJitCodeLoad code_load;
  code_load.event_ = PerfJitCodeLoad::kLoad;
256
  code_load.size_ = sizeof(code_load) + name_length + 1 + code_size;
257 258 259 260
  code_load.time_stamp_ = GetTimestamp();
  code_load.process_id_ =
      static_cast<uint32_t>(base::OS::GetCurrentProcessId());
  code_load.thread_id_ = static_cast<uint32_t>(base::OS::GetCurrentThreadId());
261
  code_load.vma_ = reinterpret_cast<uint64_t>(code_pointer);
262 263 264 265 266 267 268
  code_load.code_address_ = reinterpret_cast<uint64_t>(code_pointer);
  code_load.code_size_ = code_size;
  code_load.code_id_ = code_index_;

  code_index_++;

  LogWriteBytes(reinterpret_cast<const char*>(&code_load), sizeof(code_load));
269
  LogWriteBytes(name, name_length);
270 271 272 273
  LogWriteBytes(string_terminator, 1);
  LogWriteBytes(reinterpret_cast<const char*>(code_pointer), code_size);
}

274
namespace {
275

276 277 278 279 280
constexpr char kUnknownScriptNameString[] = "<unknown>";
constexpr size_t kUnknownScriptNameStringLen =
    arraysize(kUnknownScriptNameString) - 1;

size_t GetScriptNameLength(const SourcePositionInfo& info) {
281
  if (!info.script.is_null()) {
282
    Object name_or_url = info.script->GetNameOrSourceURL();
283
    if (name_or_url->IsString()) {
284
      String str = String::cast(name_or_url);
285 286 287 288 289 290 291 292 293 294
      if (str->IsOneByteRepresentation()) return str->length();
      int length;
      str->ToCString(DISALLOW_NULLS, FAST_STRING_TRAVERSAL, &length);
      return static_cast<size_t>(length);
    }
  }
  return kUnknownScriptNameStringLen;
}

Vector<const char> GetScriptName(const SourcePositionInfo& info,
295 296
                                 std::unique_ptr<char[]>* storage,
                                 const DisallowHeapAllocation& no_gc) {
297
  if (!info.script.is_null()) {
298
    Object name_or_url = info.script->GetNameOrSourceURL();
299
    if (name_or_url->IsSeqOneByteString()) {
300
      SeqOneByteString str = SeqOneByteString::cast(name_or_url);
301
      return {reinterpret_cast<char*>(str->GetChars(no_gc)),
302 303 304 305 306 307 308
              static_cast<size_t>(str->length())};
    } else if (name_or_url->IsString()) {
      int length;
      *storage =
          String::cast(name_or_url)
              ->ToCString(DISALLOW_NULLS, FAST_STRING_TRAVERSAL, &length);
      return {storage->get(), static_cast<size_t>(length)};
309
    }
310
  }
311
  return {kUnknownScriptNameString, kUnknownScriptNameStringLen};
312 313 314 315 316
}

SourcePositionInfo GetSourcePositionInfo(Handle<Code> code,
                                         Handle<SharedFunctionInfo> function,
                                         SourcePosition pos) {
317
  if (code->is_turbofanned()) {
318 319 320 321 322 323 324 325 326
    DisallowHeapAllocation disallow;
    return pos.InliningStack(code)[0];
  } else {
    return SourcePositionInfo(pos, function);
  }
}

}  // namespace

327
void PerfJitLogger::LogWriteDebugInfo(Code code, SharedFunctionInfo shared) {
328 329
  // Compute the entry count and get the name of the script.
  uint32_t entry_count = 0;
330
  for (SourcePositionTableIterator iterator(code->SourcePositionTable());
331 332
       !iterator.done(); iterator.Advance()) {
    entry_count++;
333
  }
334
  if (entry_count == 0) return;
335 336
  // The WasmToJS wrapper stubs have source position entries.
  if (!shared->HasSourceCode()) return;
337 338
  Isolate* isolate = shared->GetIsolate();
  Handle<Script> script(Script::cast(shared->script()), isolate);
339 340 341 342 343

  PerfJitCodeDebugInfo debug_info;

  debug_info.event_ = PerfJitCodeLoad::kDebugInfo;
  debug_info.time_stamp_ = GetTimestamp();
344
  debug_info.address_ = code->InstructionStart();
345 346 347 348 349
  debug_info.entry_count_ = entry_count;

  uint32_t size = sizeof(debug_info);
  // Add the sizes of fixed parts of entries.
  size += entry_count * sizeof(PerfJitDebugEntry);
350
  // Add the size of the name after each entry.
351

352 353
  Handle<Code> code_handle(code, isolate);
  Handle<SharedFunctionInfo> function_handle(shared, isolate);
354
  for (SourcePositionTableIterator iterator(code->SourcePositionTable());
355 356 357
       !iterator.done(); iterator.Advance()) {
    SourcePositionInfo info(GetSourcePositionInfo(code_handle, function_handle,
                                                  iterator.source_position()));
358
    size += GetScriptNameLength(info) + 1;
359
  }
360

361
  int padding = ((size + 7) & (~7)) - size;
362 363 364
  debug_info.size_ = size + padding;
  LogWriteBytes(reinterpret_cast<const char*>(&debug_info), sizeof(debug_info));

365
  Address code_start = code->InstructionStart();
366

367
  for (SourcePositionTableIterator iterator(code->SourcePositionTable());
368
       !iterator.done(); iterator.Advance()) {
369 370
    SourcePositionInfo info(GetSourcePositionInfo(code_handle, function_handle,
                                                  iterator.source_position()));
371
    PerfJitDebugEntry entry;
372 373 374
    // The entry point of the function will be placed straight after the ELF
    // header when processed by "perf inject". Adjust the position addresses
    // accordingly.
375
    entry.address_ = code_start + iterator.code_offset() + kElfHeaderSize;
376 377
    entry.line_number_ = info.line + 1;
    entry.column_ = info.column + 1;
378
    LogWriteBytes(reinterpret_cast<const char*>(&entry), sizeof(entry));
379 380 381
    // The extracted name may point into heap-objects, thus disallow GC.
    DisallowHeapAllocation no_gc;
    std::unique_ptr<char[]> name_storage;
382
    Vector<const char> name_string = GetScriptName(info, &name_storage, no_gc);
383 384
    LogWriteBytes(name_string.start(),
                  static_cast<uint32_t>(name_string.size()) + 1);
385
  }
386
  char padding_bytes[8] = {0};
387 388 389
  LogWriteBytes(padding_bytes, padding);
}

390
void PerfJitLogger::LogWriteUnwindingInfo(Code code) {
391 392 393
  PerfJitCodeUnwindingInfo unwinding_info_header;
  unwinding_info_header.event_ = PerfJitCodeLoad::kUnwindingInfo;
  unwinding_info_header.time_stamp_ = GetTimestamp();
394
  unwinding_info_header.eh_frame_hdr_size_ = EhFrameConstants::kEhFrameHdrSize;
395 396 397 398 399

  if (code->has_unwinding_info()) {
    unwinding_info_header.unwinding_size_ = code->unwinding_info_size();
    unwinding_info_header.mapped_size_ = unwinding_info_header.unwinding_size_;
  } else {
400
    unwinding_info_header.unwinding_size_ = EhFrameConstants::kEhFrameHdrSize;
401 402 403 404 405 406 407 408 409 410 411 412 413
    unwinding_info_header.mapped_size_ = 0;
  }

  int content_size = static_cast<int>(sizeof(unwinding_info_header) +
                                      unwinding_info_header.unwinding_size_);
  int padding_size = RoundUp(content_size, 8) - content_size;
  unwinding_info_header.size_ = content_size + padding_size;

  LogWriteBytes(reinterpret_cast<const char*>(&unwinding_info_header),
                sizeof(unwinding_info_header));

  if (code->has_unwinding_info()) {
    LogWriteBytes(reinterpret_cast<const char*>(code->unwinding_info_start()),
414 415 416 417
                  code->unwinding_info_size());
  } else {
    OFStream perf_output_stream(perf_output_handle_);
    EhFrameWriter::WriteEmptyEhFrame(perf_output_stream);
418 419 420
  }

  char padding_bytes[] = "\0\0\0\0\0\0\0\0";
421 422
  DCHECK_LT(padding_size, static_cast<int>(sizeof(padding_bytes)));
  LogWriteBytes(padding_bytes, static_cast<int>(padding_size));
423 424
}

425
void PerfJitLogger::CodeMoveEvent(AbstractCode from, AbstractCode to) {
426 427 428
  // We may receive a CodeMove event if a BytecodeArray object moves. Otherwise
  // code relocation is not supported.
  CHECK(from->IsBytecodeArray());
429 430 431 432 433 434 435 436 437
}

void PerfJitLogger::LogWriteBytes(const char* bytes, int size) {
  size_t rv = fwrite(bytes, 1, size, perf_output_handle_);
  DCHECK(static_cast<size_t>(size) == rv);
  USE(rv);
}

void PerfJitLogger::LogWriteHeader() {
438
  DCHECK_NOT_NULL(perf_output_handle_);
439 440 441 442 443 444
  PerfJitHeader header;

  header.magic_ = PerfJitHeader::kMagic;
  header.version_ = PerfJitHeader::kVersion;
  header.size_ = sizeof(header);
  header.elf_mach_target_ = GetElfMach();
445
  header.reserved_ = 0xDEADBEEF;
446 447
  header.process_id_ = base::OS::GetCurrentProcessId();
  header.time_stamp_ =
448 449
      static_cast<uint64_t>(V8::GetCurrentPlatform()->CurrentClockTimeMillis() *
                            base::Time::kMicrosecondsPerMillisecond);
450 451 452 453 454 455 456 457
  header.flags_ = 0;

  LogWriteBytes(reinterpret_cast<const char*>(&header), sizeof(header));
}

#endif  // V8_OS_LINUX
}  // namespace internal
}  // namespace v8