perf-jit.cc 18.6 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
// 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.

28
#include "src/diagnostics/perf-jit.h"
29

30 31
#include <memory>

32 33
#include "src/codegen/assembler.h"
#include "src/codegen/source-position-table.h"
34
#include "src/diagnostics/eh-frame.h"
35
#include "src/objects/objects-inl.h"
36
#include "src/snapshot/embedded/embedded-data.h"
37
#include "src/utils/ostreams.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 44
// jumbo: conflicts with v8::internal::InstanceType::MAP_TYPE
#undef MAP_TYPE  // NOLINT
45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67
#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 {
68 69 70 71 72 73 74
  enum PerfJitEvent {
    kLoad = 0,
    kMove = 1,
    kDebugInfo = 2,
    kClose = 3,
    kUnwindingInfo = 4
  };
75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93

  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_;
94
  // Followed by null-terminated name or \0xFF\0 if same as previous.
95 96 97 98 99 100 101 102
};

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

103 104 105 106 107 108 109
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.
};

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

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

115 116 117 118 119 120 121
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;

122 123 124 125 126 127 128 129 130 131
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);

132
  int fd = open(perf_dump_name.begin(), O_CREAT | O_TRUNC | O_RDWR, 0666);
133 134 135 136 137 138 139 140
  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;

141
  setvbuf(perf_output_handle_, nullptr, _IOFBF, kLogBufferSize);
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 168
}

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);
}

169
PerfJitLogger::PerfJitLogger(Isolate* isolate) : CodeEventLogger(isolate) {
170 171 172 173 174 175 176 177 178
  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();
  }
179 180
}

181 182 183 184 185 186 187 188 189
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();
  }
}
190 191 192 193 194 195 196 197 198 199

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;
}

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

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

  if (perf_output_handle_ == nullptr) return;

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

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

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

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

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

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

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

  if (perf_output_handle_ == nullptr) return;

246 247 248 249
  if (FLAG_perf_prof_annotate_wasm) {
    LogWriteDebugInfo(code);
  }

250
  WriteJitCodeLoadEntry(code->instructions().begin(),
251 252 253 254 255 256
                        code->instructions().length(), name, length);
}

void PerfJitLogger::WriteJitCodeLoadEntry(const uint8_t* code_pointer,
                                          uint32_t code_size, const char* name,
                                          int name_length) {
257
  static const char string_terminator[] = "\0";
258 259 260

  PerfJitCodeLoad code_load;
  code_load.event_ = PerfJitCodeLoad::kLoad;
261
  code_load.size_ = sizeof(code_load) + name_length + 1 + code_size;
262 263 264 265
  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());
266
  code_load.vma_ = reinterpret_cast<uint64_t>(code_pointer);
267 268 269 270 271 272 273
  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));
274
  LogWriteBytes(name, name_length);
275 276 277 278
  LogWriteBytes(string_terminator, 1);
  LogWriteBytes(reinterpret_cast<const char*>(code_pointer), code_size);
}

279
namespace {
280

281 282 283 284 285
constexpr char kUnknownScriptNameString[] = "<unknown>";
constexpr size_t kUnknownScriptNameStringLen =
    arraysize(kUnknownScriptNameString) - 1;

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

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

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

}  // namespace

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

  PerfJitCodeDebugInfo debug_info;

  debug_info.event_ = PerfJitCodeLoad::kDebugInfo;
  debug_info.time_stamp_ = GetTimestamp();
348
  debug_info.address_ = code.InstructionStart();
349 350 351 352 353
  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);
354
  // Add the size of the name after each entry.
355

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

365
  int padding = ((size + 7) & (~7)) - size;
366 367 368
  debug_info.size_ = size + padding;
  LogWriteBytes(reinterpret_cast<const char*>(&debug_info), sizeof(debug_info));

369
  Address code_start = code.InstructionStart();
370

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

394 395 396 397 398 399 400 401 402 403 404 405 406 407 408 409 410 411 412 413 414 415 416 417 418 419 420 421 422 423 424 425 426 427 428 429 430 431 432 433 434 435 436 437 438 439 440 441 442 443 444 445 446 447 448 449 450 451 452 453 454 455 456 457 458 459 460
void PerfJitLogger::LogWriteDebugInfo(const wasm::WasmCode* code) {
  wasm::WasmModuleSourceMap* source_map =
      code->native_module()->GetWasmSourceMap();
  wasm::WireBytesRef code_ref =
      code->native_module()->module()->functions[code->index()].code;
  uint32_t code_offset = code_ref.offset();
  uint32_t code_end_offset = code_ref.end_offset();

  uint32_t entry_count = 0;
  uint32_t size = 0;

  if (!source_map || !source_map->IsValid() ||
      !source_map->HasSource(code_offset, code_end_offset)) {
    return;
  }

  for (SourcePositionTableIterator iterator(code->source_positions());
       !iterator.done(); iterator.Advance()) {
    uint32_t offset = iterator.source_position().ScriptOffset() + code_offset;
    if (!source_map->HasValidEntry(code_offset, offset)) continue;
    entry_count++;
    size += source_map->GetFilename(offset).size() + 1;
  }

  if (entry_count == 0) return;

  PerfJitCodeDebugInfo debug_info;

  debug_info.event_ = PerfJitCodeLoad::kDebugInfo;
  debug_info.time_stamp_ = GetTimestamp();
  debug_info.address_ =
      reinterpret_cast<uintptr_t>(code->instructions().begin());
  debug_info.entry_count_ = entry_count;

  size += sizeof(debug_info);
  // Add the sizes of fixed parts of entries.
  size += entry_count * sizeof(PerfJitDebugEntry);

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

  uintptr_t code_begin =
      reinterpret_cast<uintptr_t>(code->instructions().begin());

  for (SourcePositionTableIterator iterator(code->source_positions());
       !iterator.done(); iterator.Advance()) {
    uint32_t offset = iterator.source_position().ScriptOffset() + code_offset;
    if (!source_map->HasValidEntry(code_offset, offset)) continue;
    PerfJitDebugEntry entry;
    // The entry point of the function will be placed straight after the ELF
    // header when processed by "perf inject". Adjust the position addresses
    // accordingly.
    entry.address_ = code_begin + iterator.code_offset() + kElfHeaderSize;
    entry.line_number_ =
        static_cast<int>(source_map->GetSourceLine(offset)) + 1;
    entry.column_ = 1;
    LogWriteBytes(reinterpret_cast<const char*>(&entry), sizeof(entry));
    std::string name_string = source_map->GetFilename(offset);
    LogWriteBytes(name_string.c_str(),
                  static_cast<int>(name_string.size() + 1));
  }

  char padding_bytes[8] = {0};
  LogWriteBytes(padding_bytes, padding);
}

461
void PerfJitLogger::LogWriteUnwindingInfo(Code code) {
462 463 464
  PerfJitCodeUnwindingInfo unwinding_info_header;
  unwinding_info_header.event_ = PerfJitCodeLoad::kUnwindingInfo;
  unwinding_info_header.time_stamp_ = GetTimestamp();
465
  unwinding_info_header.eh_frame_hdr_size_ = EhFrameConstants::kEhFrameHdrSize;
466

467 468
  if (code.has_unwinding_info()) {
    unwinding_info_header.unwinding_size_ = code.unwinding_info_size();
469 470
    unwinding_info_header.mapped_size_ = unwinding_info_header.unwinding_size_;
  } else {
471
    unwinding_info_header.unwinding_size_ = EhFrameConstants::kEhFrameHdrSize;
472 473 474 475 476 477 478 479 480 481 482
    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));

483 484 485
  if (code.has_unwinding_info()) {
    LogWriteBytes(reinterpret_cast<const char*>(code.unwinding_info_start()),
                  code.unwinding_info_size());
486 487 488
  } else {
    OFStream perf_output_stream(perf_output_handle_);
    EhFrameWriter::WriteEmptyEhFrame(perf_output_stream);
489 490 491
  }

  char padding_bytes[] = "\0\0\0\0\0\0\0\0";
492 493
  DCHECK_LT(padding_size, static_cast<int>(sizeof(padding_bytes)));
  LogWriteBytes(padding_bytes, static_cast<int>(padding_size));
494 495
}

496
void PerfJitLogger::CodeMoveEvent(AbstractCode from, AbstractCode to) {
497 498
  // We may receive a CodeMove event if a BytecodeArray object moves. Otherwise
  // code relocation is not supported.
499
  CHECK(from.IsBytecodeArray());
500 501 502 503 504 505 506 507 508
}

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() {
509
  DCHECK_NOT_NULL(perf_output_handle_);
510 511 512 513 514 515
  PerfJitHeader header;

  header.magic_ = PerfJitHeader::kMagic;
  header.version_ = PerfJitHeader::kVersion;
  header.size_ = sizeof(header);
  header.elf_mach_target_ = GetElfMach();
516
  header.reserved_ = 0xDEADBEEF;
517 518
  header.process_id_ = base::OS::GetCurrentProcessId();
  header.time_stamp_ =
519 520
      static_cast<uint64_t>(V8::GetCurrentPlatform()->CurrentClockTimeMillis() *
                            base::Time::kMicrosecondsPerMillisecond);
521 522 523 524 525 526 527 528
  header.flags_ = 0;

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

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