log.cc 55.7 KB
Newer Older
danno@chromium.org's avatar
danno@chromium.org committed
1
// Copyright 2011 the V8 project authors. All rights reserved.
2 3
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
4

5 6 7
#include "src/log.h"

#include <cstdarg>
8
#include <memory>
9
#include <sstream>
10

11
#include "src/bailout-reason.h"
12
#include "src/base/platform/platform.h"
13 14
#include "src/bootstrapper.h"
#include "src/code-stubs.h"
15
#include "src/counters.h"
16 17
#include "src/deoptimizer.h"
#include "src/global-handles.h"
18 19
#include "src/interpreter/bytecodes.h"
#include "src/interpreter/interpreter.h"
20
#include "src/libsampler/sampler.h"
21
#include "src/log-inl.h"
22 23
#include "src/log-utils.h"
#include "src/macro-assembler.h"
24
#include "src/perf-jit.h"
lpy's avatar
lpy committed
25
#include "src/profiler/profiler-listener.h"
26
#include "src/profiler/tick-sample.h"
27
#include "src/runtime-profiler.h"
28
#include "src/source-position-table.h"
29
#include "src/string-stream.h"
30
#include "src/tracing/tracing-category-observer.h"
31
#include "src/vm-state-inl.h"
32

33 34
namespace v8 {
namespace internal {
35

36
#define DECLARE_EVENT(ignore1, name) name,
37 38
static const char* kLogEventsNames[CodeEventListener::NUMBER_OF_LOG_EVENTS] = {
    LOG_EVENTS_AND_TAGS_LIST(DECLARE_EVENT)};
39 40
#undef DECLARE_EVENT

41 42
static const char* ComputeMarker(SharedFunctionInfo* shared,
                                 AbstractCode* code) {
43
  switch (code->kind()) {
44 45
    case AbstractCode::FUNCTION:
    case AbstractCode::INTERPRETED_FUNCTION:
46
      return shared->optimization_disabled() ? "" : "~";
47
    case AbstractCode::OPTIMIZED_FUNCTION:
48 49 50
      return "*";
    default:
      return "";
51 52 53 54
  }
}


55
class CodeEventLogger::NameBuffer {
56
 public:
57
  NameBuffer() { Reset(); }
58

59 60 61
  void Reset() {
    utf8_pos_ = 0;
  }
62

63
  void Init(CodeEventListener::LogEventsAndTags tag) {
64 65 66 67 68 69 70 71 72 73 74
    Reset();
    AppendBytes(kLogEventsNames[tag]);
    AppendByte(':');
  }

  void AppendName(Name* name) {
    if (name->IsString()) {
      AppendString(String::cast(name));
    } else {
      Symbol* symbol = Symbol::cast(name);
      AppendBytes("symbol(");
75
      if (!symbol->name()->IsUndefined(symbol->GetIsolate())) {
76 77 78
        AppendBytes("\"");
        AppendString(String::cast(symbol->name()));
        AppendBytes("\" ");
79
      }
80 81 82
      AppendBytes("hash ");
      AppendHex(symbol->Hash());
      AppendByte(')');
83
    }
84
  }
85

86 87 88 89 90 91 92 93 94 95 96 97 98 99
  void AppendString(String* str) {
    if (str == NULL) return;
    int uc16_length = Min(str->length(), kUtf16BufferSize);
    String::WriteToFlat(str, utf16_buffer, 0, uc16_length);
    int previous = unibrow::Utf16::kNoPreviousCharacter;
    for (int i = 0; i < uc16_length && utf8_pos_ < kUtf8BufferSize; ++i) {
      uc16 c = utf16_buffer[i];
      if (c <= unibrow::Utf8::kMaxOneByteChar) {
        utf8_buffer_[utf8_pos_++] = static_cast<char>(c);
      } else {
        int char_length = unibrow::Utf8::Length(c, previous);
        if (utf8_pos_ + char_length > kUtf8BufferSize) break;
        unibrow::Utf8::Encode(utf8_buffer_ + utf8_pos_, c, previous);
        utf8_pos_ += char_length;
100
      }
101
      previous = c;
102
    }
103
  }
104

105 106
  void AppendBytes(const char* bytes, int size) {
    size = Min(size, kUtf8BufferSize - utf8_pos_);
107
    MemCopy(utf8_buffer_ + utf8_pos_, bytes, size);
108 109
    utf8_pos_ += size;
  }
110

111 112 113
  void AppendBytes(const char* bytes) {
    AppendBytes(bytes, StrLength(bytes));
  }
114

115 116 117 118
  void AppendByte(char c) {
    if (utf8_pos_ >= kUtf8BufferSize) return;
    utf8_buffer_[utf8_pos_++] = c;
  }
119

120
  void AppendInt(int n) {
121 122 123
    int space = kUtf8BufferSize - utf8_pos_;
    if (space <= 0) return;
    Vector<char> buffer(utf8_buffer_ + utf8_pos_, space);
124
    int size = SNPrintF(buffer, "%d", n);
125 126
    if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {
      utf8_pos_ += size;
127
    }
128
  }
129

130
  void AppendHex(uint32_t n) {
131 132 133
    int space = kUtf8BufferSize - utf8_pos_;
    if (space <= 0) return;
    Vector<char> buffer(utf8_buffer_ + utf8_pos_, space);
134
    int size = SNPrintF(buffer, "%x", n);
135 136
    if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {
      utf8_pos_ += size;
137
    }
138
  }
139

140 141
  const char* get() { return utf8_buffer_; }
  int size() const { return utf8_pos_; }
142 143

 private:
144
  static const int kUtf8BufferSize = 512;
145
  static const int kUtf16BufferSize = kUtf8BufferSize;
146

147 148 149
  int utf8_pos_;
  char utf8_buffer_[kUtf8BufferSize];
  uc16 utf16_buffer[kUtf16BufferSize];
150 151 152
};


153 154 155 156
CodeEventLogger::CodeEventLogger() : name_buffer_(new NameBuffer) { }

CodeEventLogger::~CodeEventLogger() { delete name_buffer_; }

157
void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
158
                                      AbstractCode* code, const char* comment) {
159 160 161
  name_buffer_->Init(tag);
  name_buffer_->AppendBytes(comment);
  LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());
162 163
}

164
void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
165
                                      AbstractCode* code, Name* name) {
166 167 168
  name_buffer_->Init(tag);
  name_buffer_->AppendName(name);
  LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());
169 170
}

171
void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
172
                                      AbstractCode* code,
173
                                      SharedFunctionInfo* shared, Name* name) {
174
  name_buffer_->Init(tag);
175
  name_buffer_->AppendBytes(ComputeMarker(shared, code));
176 177
  name_buffer_->AppendName(name);
  LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());
178 179
}

180
void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
181
                                      AbstractCode* code,
182
                                      SharedFunctionInfo* shared, Name* source,
183
                                      int line, int column) {
184
  name_buffer_->Init(tag);
185
  name_buffer_->AppendBytes(ComputeMarker(shared, code));
186 187
  name_buffer_->AppendString(shared->DebugName());
  name_buffer_->AppendByte(' ');
188
  if (source->IsString()) {
189
    name_buffer_->AppendString(String::cast(source));
190
  } else {
191 192 193
    name_buffer_->AppendBytes("symbol(hash ");
    name_buffer_->AppendHex(Name::cast(source)->Hash());
    name_buffer_->AppendByte(')');
194
  }
195 196 197
  name_buffer_->AppendByte(':');
  name_buffer_->AppendInt(line);
  LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());
198 199
}

200
void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
201
                                      AbstractCode* code, int args_count) {
202 203 204
  name_buffer_->Init(tag);
  name_buffer_->AppendInt(args_count);
  LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());
205 206
}

207 208
void CodeEventLogger::RegExpCodeCreateEvent(AbstractCode* code,
                                            String* source) {
209
  name_buffer_->Init(CodeEventListener::REG_EXP_TAG);
210 211
  name_buffer_->AppendString(source);
  LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());
212 213 214
}


215 216 217 218
// Linux perf tool logging support
class PerfBasicLogger : public CodeEventLogger {
 public:
  PerfBasicLogger();
219
  ~PerfBasicLogger() override;
220

221 222 223
  void CodeMoveEvent(AbstractCode* from, Address to) override {}
  void CodeDisableOptEvent(AbstractCode* code,
                           SharedFunctionInfo* shared) override {}
224 225

 private:
226 227
  void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
                         const char* name, int length) override;
228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243 244

  // Extension added to V8 log file name to get the low-level log name.
  static const char kFilenameFormatString[];
  static const int kFilenameBufferPadding;

  FILE* perf_output_handle_;
};

const char PerfBasicLogger::kFilenameFormatString[] = "/tmp/perf-%d.map";
// Extra space for the PID in the filename
const int PerfBasicLogger::kFilenameBufferPadding = 16;

PerfBasicLogger::PerfBasicLogger()
    : perf_output_handle_(NULL) {
  // Open the perf JIT dump file.
  int bufferSize = sizeof(kFilenameFormatString) + kFilenameBufferPadding;
  ScopedVector<char> perf_dump_name(bufferSize);
245
  int size = SNPrintF(
246 247
      perf_dump_name,
      kFilenameFormatString,
248
      base::OS::GetCurrentProcessId());
249
  CHECK_NE(size, -1);
250 251
  perf_output_handle_ =
      base::OS::FOpen(perf_dump_name.start(), base::OS::LogFileOpenMode);
252
  CHECK_NOT_NULL(perf_output_handle_);
253
  setvbuf(perf_output_handle_, NULL, _IOLBF, 0);
254 255 256 257 258 259 260 261
}


PerfBasicLogger::~PerfBasicLogger() {
  fclose(perf_output_handle_);
  perf_output_handle_ = NULL;
}

262 263
void PerfBasicLogger::LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo*,
                                        const char* name, int length) {
264
  if (FLAG_perf_basic_prof_only_functions &&
265 266 267
      (code->kind() != AbstractCode::FUNCTION &&
       code->kind() != AbstractCode::INTERPRETED_FUNCTION &&
       code->kind() != AbstractCode::OPTIMIZED_FUNCTION)) {
268 269 270
    return;
  }

271 272 273 274 275 276 277 278 279
  // Linux perf expects hex literals without a leading 0x, while some
  // implementations of printf might prepend one when using the %p format
  // for pointers, leading to wrongly formatted JIT symbols maps.
  //
  // Instead, we use V8PRIxPTR format string and cast pointer to uintpr_t,
  // so that we have control over the exact output format.
  base::OS::FPrint(perf_output_handle_, "%" V8PRIxPTR " %x %.*s\n",
                   reinterpret_cast<uintptr_t>(code->instruction_start()),
                   code->instruction_size(), length, name);
280 281
}

282
// Low-level logging support.
283 284
#define LL_LOG(Call) if (ll_logger_) ll_logger_->Call;

285
class LowLevelLogger : public CodeEventLogger {
286 287
 public:
  explicit LowLevelLogger(const char* file_name);
288
  ~LowLevelLogger() override;
289

290 291 292
  void CodeMoveEvent(AbstractCode* from, Address to) override;
  void CodeDisableOptEvent(AbstractCode* code,
                           SharedFunctionInfo* shared) override {}
293
  void SnapshotPositionEvent(HeapObject* obj, int pos);
294
  void CodeMovingGCEvent() override;
295 296

 private:
297 298
  void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
                         const char* name, int length) override;
299

300
  // Low-level profiling event structures.
301 302 303 304 305 306 307 308 309 310 311 312 313 314 315 316 317 318 319 320 321 322 323 324 325 326 327 328 329 330 331 332 333 334 335 336 337 338
  struct CodeCreateStruct {
    static const char kTag = 'C';

    int32_t name_size;
    Address code_address;
    int32_t code_size;
  };


  struct CodeMoveStruct {
    static const char kTag = 'M';

    Address from_address;
    Address to_address;
  };


  static const char kCodeMovingGCTag = 'G';


  // Extension added to V8 log file name to get the low-level log name.
  static const char kLogExt[];

  void LogCodeInfo();
  void LogWriteBytes(const char* bytes, int size);

  template <typename T>
  void LogWriteStruct(const T& s) {
    char tag = T::kTag;
    LogWriteBytes(reinterpret_cast<const char*>(&tag), sizeof(tag));
    LogWriteBytes(reinterpret_cast<const char*>(&s), sizeof(s));
  }

  FILE* ll_output_handle_;
};

const char LowLevelLogger::kLogExt[] = ".ll";

339 340 341 342 343
LowLevelLogger::LowLevelLogger(const char* name)
    : ll_output_handle_(NULL) {
  // Open the low-level log file.
  size_t len = strlen(name);
  ScopedVector<char> ll_name(static_cast<int>(len + sizeof(kLogExt)));
344 345
  MemCopy(ll_name.start(), name, len);
  MemCopy(ll_name.start() + len, kLogExt, sizeof(kLogExt));
346 347
  ll_output_handle_ =
      base::OS::FOpen(ll_name.start(), base::OS::LogFileOpenMode);
348
  setvbuf(ll_output_handle_, NULL, _IOLBF, 0);
349 350 351 352 353 354 355 356 357 358 359 360 361 362

  LogCodeInfo();
}


LowLevelLogger::~LowLevelLogger() {
  fclose(ll_output_handle_);
  ll_output_handle_ = NULL;
}


void LowLevelLogger::LogCodeInfo() {
#if V8_TARGET_ARCH_IA32
  const char arch[] = "ia32";
363
#elif V8_TARGET_ARCH_X64 && V8_TARGET_ARCH_64_BIT
364
  const char arch[] = "x64";
365 366
#elif V8_TARGET_ARCH_X64 && V8_TARGET_ARCH_32_BIT
  const char arch[] = "x32";
367 368
#elif V8_TARGET_ARCH_ARM
  const char arch[] = "arm";
369 370
#elif V8_TARGET_ARCH_PPC
  const char arch[] = "ppc";
371 372
#elif V8_TARGET_ARCH_MIPS
  const char arch[] = "mips";
danno@chromium.org's avatar
danno@chromium.org committed
373 374
#elif V8_TARGET_ARCH_X87
  const char arch[] = "x87";
375 376
#elif V8_TARGET_ARCH_ARM64
  const char arch[] = "arm64";
377 378
#elif V8_TARGET_ARCH_S390
  const char arch[] = "s390";
379 380 381 382 383 384
#else
  const char arch[] = "unknown";
#endif
  LogWriteBytes(arch, sizeof(arch));
}

385 386
void LowLevelLogger::LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo*,
                                       const char* name, int length) {
387
  CodeCreateStruct event;
388
  event.name_size = length;
389 390 391
  event.code_address = code->instruction_start();
  event.code_size = code->instruction_size();
  LogWriteStruct(event);
392
  LogWriteBytes(name, length);
393 394 395 396 397
  LogWriteBytes(
      reinterpret_cast<const char*>(code->instruction_start()),
      code->instruction_size());
}

398
void LowLevelLogger::CodeMoveEvent(AbstractCode* from, Address to) {
399
  CodeMoveStruct event;
400 401 402
  event.from_address = from->instruction_start();
  size_t header_size = from->instruction_start() - from->address();
  event.to_address = to + header_size;
403 404 405 406 407 408
  LogWriteStruct(event);
}


void LowLevelLogger::LogWriteBytes(const char* bytes, int size) {
  size_t rv = fwrite(bytes, 1, size, ll_output_handle_);
409
  DCHECK(static_cast<size_t>(size) == rv);
410 411 412 413 414 415 416 417 418 419 420 421 422 423
  USE(rv);
}


void LowLevelLogger::CodeMovingGCEvent() {
  const char tag = kCodeMovingGCTag;

  LogWriteBytes(&tag, sizeof(tag));
}

class JitLogger : public CodeEventLogger {
 public:
  explicit JitLogger(JitCodeEventHandler code_event_handler);

424 425 426 427 428 429
  void CodeMoveEvent(AbstractCode* from, Address to) override;
  void CodeDisableOptEvent(AbstractCode* code,
                           SharedFunctionInfo* shared) override {}
  void AddCodeLinePosInfoEvent(void* jit_handler_data, int pc_offset,
                               int position,
                               JitCodeEvent::PositionType position_type);
430

431
  void* StartCodePosInfoEvent();
432
  void EndCodePosInfoEvent(AbstractCode* code, void* jit_handler_data);
433 434

 private:
435 436
  void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
                         const char* name, int length) override;
437 438

  JitCodeEventHandler code_event_handler_;
439
  base::Mutex logger_mutex_;
440 441 442 443 444 445 446
};


JitLogger::JitLogger(JitCodeEventHandler code_event_handler)
    : code_event_handler_(code_event_handler) {
}

447 448
void JitLogger::LogRecordedBuffer(AbstractCode* code,
                                  SharedFunctionInfo* shared, const char* name,
449
                                  int length) {
450 451 452 453 454
  JitCodeEvent event;
  memset(&event, 0, sizeof(event));
  event.type = JitCodeEvent::CODE_ADDED;
  event.code_start = code->instruction_start();
  event.code_len = code->instruction_size();
455
  Handle<SharedFunctionInfo> shared_function_handle;
456
  if (shared && shared->script()->IsScript()) {
457
    shared_function_handle = Handle<SharedFunctionInfo>(shared);
458
  }
459
  event.script = ToApiHandle<v8::UnboundScript>(shared_function_handle);
460 461
  event.name.str = name;
  event.name.len = length;
462 463 464
  code_event_handler_(&event);
}

465
void JitLogger::CodeMoveEvent(AbstractCode* from, Address to) {
466
  base::LockGuard<base::Mutex> guard(&logger_mutex_);
467 468 469

  JitCodeEvent event;
  event.type = JitCodeEvent::CODE_MOVED;
470 471
  event.code_start = from->instruction_start();
  event.code_len = from->instruction_size();
472 473

  // Calculate the header size.
474
  const size_t header_size = from->instruction_start() - from->address();
475 476

  // Calculate the new start address of the instructions.
477
  event.new_code_start = to + header_size;
478 479 480 481 482 483 484 485 486 487 488 489 490 491 492 493 494 495 496 497 498 499 500 501 502 503 504 505 506 507

  code_event_handler_(&event);
}

void JitLogger::AddCodeLinePosInfoEvent(
    void* jit_handler_data,
    int pc_offset,
    int position,
    JitCodeEvent::PositionType position_type) {
  JitCodeEvent event;
  memset(&event, 0, sizeof(event));
  event.type = JitCodeEvent::CODE_ADD_LINE_POS_INFO;
  event.user_data = jit_handler_data;
  event.line_info.offset = pc_offset;
  event.line_info.pos = position;
  event.line_info.position_type = position_type;

  code_event_handler_(&event);
}


void* JitLogger::StartCodePosInfoEvent() {
  JitCodeEvent event;
  memset(&event, 0, sizeof(event));
  event.type = JitCodeEvent::CODE_START_LINE_INFO_RECORDING;

  code_event_handler_(&event);
  return event.user_data;
}

508 509
void JitLogger::EndCodePosInfoEvent(AbstractCode* code,
                                    void* jit_handler_data) {
510 511 512 513 514 515 516 517 518 519
  JitCodeEvent event;
  memset(&event, 0, sizeof(event));
  event.type = JitCodeEvent::CODE_END_LINE_INFO_RECORDING;
  event.code_start = code->instruction_start();
  event.user_data = jit_handler_data;

  code_event_handler_(&event);
}


520 521 522 523 524 525 526 527 528 529 530 531 532 533 534 535 536 537 538 539 540 541 542 543 544
// TODO(lpy): Keeping sampling thread inside V8 is a workaround currently,
// the reason is to reduce code duplication during migration to sampler library,
// sampling thread, as well as the sampler, will be moved to D8 eventually.
class SamplingThread : public base::Thread {
 public:
  static const int kSamplingThreadStackSize = 64 * KB;

  SamplingThread(sampler::Sampler* sampler, int interval)
      : base::Thread(base::Thread::Options("SamplingThread",
                                           kSamplingThreadStackSize)),
        sampler_(sampler),
        interval_(interval) {}
  void Run() override {
    while (sampler_->IsProfiling()) {
      sampler_->DoSample();
      base::OS::Sleep(base::TimeDelta::FromMilliseconds(interval_));
    }
  }

 private:
  sampler::Sampler* sampler_;
  const int interval_;
};


545 546 547 548 549
// The Profiler samples pc and sp values for the main thread.
// Each sample is appended to a circular buffer.
// An independent thread removes data and writes it to the log.
// This design minimizes the time spent in the sampler.
//
550
class Profiler: public base::Thread {
551
 public:
552
  explicit Profiler(Isolate* isolate);
553 554 555 556
  void Engage();
  void Disengage();

  // Inserts collected profiling data into buffer.
557
  void Insert(v8::TickSample* sample) {
558 559 560
    if (paused_)
      return;

561
    if (Succ(head_) == static_cast<int>(base::NoBarrier_Load(&tail_))) {
562 563 564 565
      overflow_ = true;
    } else {
      buffer_[head_] = *sample;
      head_ = Succ(head_);
566
      buffer_semaphore_.Signal();  // Tell we have an element.
567 568 569
    }
  }

570 571 572 573 574 575 576
  virtual void Run();

  // Pause and Resume TickSample data collection.
  void pause() { paused_ = true; }
  void resume() { paused_ = false; }

 private:
577
  // Waits for a signal and removes profiling data.
578
  bool Remove(v8::TickSample* sample) {
579
    buffer_semaphore_.Wait();  // Wait for an element.
580
    *sample = buffer_[base::NoBarrier_Load(&tail_)];
581
    bool result = overflow_;
582 583
    base::NoBarrier_Store(&tail_, static_cast<base::Atomic32>(
                                      Succ(base::NoBarrier_Load(&tail_))));
584 585 586 587 588 589 590
    overflow_ = false;
    return result;
  }

  // Returns the next index in the cyclic buffer.
  int Succ(int index) { return (index + 1) % kBufferSize; }

591
  Isolate* isolate_;
592 593 594
  // Cyclic buffer for communicating profiling samples
  // between the signal handler and the worker thread.
  static const int kBufferSize = 128;
595
  v8::TickSample buffer_[kBufferSize];  // Buffer storage.
596
  int head_;  // Index to the buffer head.
597
  base::Atomic32 tail_;             // Index to the buffer tail.
598
  bool overflow_;  // Tell whether a buffer overflow has occurred.
599
  // Sempahore used for buffer synchronization.
600
  base::Semaphore buffer_semaphore_;
601

602 603 604
  // Tells whether profiler is engaged, that is, processing thread is stated.
  bool engaged_;

605
  // Tells whether worker thread should continue running.
606
  base::Atomic32 running_;
607 608

  // Tells whether we are currently recording tick samples.
609
  bool paused_;
610 611 612 613 614 615 616
};


//
// Ticker used to provide ticks to the profiler and the sliding state
// window.
//
617
class Ticker: public sampler::Sampler {
618
 public:
619 620 621 622
  Ticker(Isolate* isolate, int interval)
      : sampler::Sampler(reinterpret_cast<v8::Isolate*>(isolate)),
        profiler_(nullptr),
        sampling_thread_(new SamplingThread(this, interval)) {}
623

624 625 626
  ~Ticker() {
    if (IsActive()) Stop();
    delete sampling_thread_;
627 628 629
  }

  void SetProfiler(Profiler* profiler) {
630
    DCHECK(profiler_ == nullptr);
631
    profiler_ = profiler;
632
    IncreaseProfilingDepth();
633
    if (!IsActive()) Start();
634
    sampling_thread_->StartSynchronously();
635 636 637
  }

  void ClearProfiler() {
638
    profiler_ = nullptr;
639
    if (IsActive()) Stop();
640
    DecreaseProfilingDepth();
641 642 643 644
    sampling_thread_->Join();
  }

  void SampleStack(const v8::RegisterState& state) override {
lpy's avatar
lpy committed
645
    if (!profiler_) return;
646 647 648
    Isolate* isolate = reinterpret_cast<Isolate*>(this->isolate());
    TickSample sample;
    sample.Init(isolate, state, TickSample::kIncludeCEntryFrame, true);
lpy's avatar
lpy committed
649
    profiler_->Insert(&sample);
650 651 652 653
  }

 private:
  Profiler* profiler_;
654
  SamplingThread* sampling_thread_;
655 656 657 658 659 660
};


//
// Profiler implementation.
//
661
Profiler::Profiler(Isolate* isolate)
662
    : base::Thread(Options("v8:Profiler")),
663
      isolate_(isolate),
664
      head_(0),
665
      overflow_(false),
666
      buffer_semaphore_(0),
667
      engaged_(false),
668 669
      paused_(false) {
  base::NoBarrier_Store(&tail_, 0);
670
  base::NoBarrier_Store(&running_, 0);
671
}
672 673 674


void Profiler::Engage() {
675 676 677
  if (engaged_) return;
  engaged_ = true;

678 679
  std::vector<base::OS::SharedLibraryAddress> addresses =
      base::OS::GetSharedLibraryAddresses();
680
  for (size_t i = 0; i < addresses.size(); ++i) {
681 682 683
    LOG(isolate_,
        SharedLibraryEvent(addresses[i].library_path, addresses[i].start,
                           addresses[i].end, addresses[i].aslr_slide));
684
  }
685 686

  // Start thread processing the profiler buffer.
687
  base::NoBarrier_Store(&running_, 1);
688 689 690
  Start();

  // Register to get ticks.
yurys@chromium.org's avatar
yurys@chromium.org committed
691 692
  Logger* logger = isolate_->logger();
  logger->ticker_->SetProfiler(this);
693

yurys@chromium.org's avatar
yurys@chromium.org committed
694
  logger->ProfilerBeginEvent();
695 696 697 698
}


void Profiler::Disengage() {
699 700
  if (!engaged_) return;

701
  // Stop receiving ticks.
702
  isolate_->logger()->ticker_->ClearProfiler();
703

704 705 706
  // Terminate the worker thread by setting running_ to false,
  // inserting a fake element in the queue and then wait for
  // the thread to terminate.
707
  base::NoBarrier_Store(&running_, 0);
708
  v8::TickSample sample;
709 710 711 712
  // Reset 'paused_' flag, otherwise semaphore may not be signalled.
  resume();
  Insert(&sample);
  Join();
713

dcarney@chromium.org's avatar
dcarney@chromium.org committed
714
  LOG(isolate_, UncheckedStringEvent("profiler", "end"));
715 716
}

717

718
void Profiler::Run() {
719
  v8::TickSample sample;
720
  bool overflow = Remove(&sample);
721
  while (base::NoBarrier_Load(&running_)) {
722 723 724
    LOG(isolate_, TickEvent(&sample, overflow));
    overflow = Remove(&sample);
  }
725 726
}

727

728 729 730
//
// Logger class implementation.
//
731

732
Logger::Logger(Isolate* isolate)
733 734 735 736 737 738 739 740 741 742 743 744
    : isolate_(isolate),
      ticker_(NULL),
      profiler_(NULL),
      log_events_(NULL),
      is_logging_(false),
      log_(new Log(this)),
      perf_basic_logger_(NULL),
      perf_jit_logger_(NULL),
      ll_logger_(NULL),
      jit_logger_(NULL),
      listeners_(5),
      is_initialized_(false) {}
745

746 747
Logger::~Logger() {
  delete log_;
748
}
749

750
void Logger::addCodeEventListener(CodeEventListener* listener) {
751 752 753
  bool result = isolate_->code_event_dispatcher()->AddListener(listener);
  USE(result);
  DCHECK(result);
754 755 756
}

void Logger::removeCodeEventListener(CodeEventListener* listener) {
757
  isolate_->code_event_dispatcher()->RemoveListener(listener);
758 759
}

760
void Logger::ProfilerBeginEvent() {
761
  if (!log_->IsEnabled()) return;
762
  Log::MessageBuilder msg(log_);
763
  msg.Append("profiler,\"begin\",%d", kSamplingIntervalMs);
764 765 766
  msg.WriteToLogFile();
}

767

768
void Logger::StringEvent(const char* name, const char* value) {
769 770 771 772 773
  if (FLAG_log) UncheckedStringEvent(name, value);
}


void Logger::UncheckedStringEvent(const char* name, const char* value) {
774
  if (!log_->IsEnabled()) return;
775
  Log::MessageBuilder msg(log_);
776
  msg.Append("%s,\"%s\"", name, value);
777
  msg.WriteToLogFile();
778 779 780 781
}


void Logger::IntEvent(const char* name, int value) {
782 783 784 785
  if (FLAG_log) UncheckedIntEvent(name, value);
}


786 787 788 789 790
void Logger::IntPtrTEvent(const char* name, intptr_t value) {
  if (FLAG_log) UncheckedIntPtrTEvent(name, value);
}


791
void Logger::UncheckedIntEvent(const char* name, int value) {
792
  if (!log_->IsEnabled()) return;
793
  Log::MessageBuilder msg(log_);
794
  msg.Append("%s,%d", name, value);
795
  msg.WriteToLogFile();
796 797 798
}


799
void Logger::UncheckedIntPtrTEvent(const char* name, intptr_t value) {
800
  if (!log_->IsEnabled()) return;
801
  Log::MessageBuilder msg(log_);
jfb's avatar
jfb committed
802
  msg.Append("%s,%" V8PRIdPTR, name, value);
803 804 805 806
  msg.WriteToLogFile();
}


807
void Logger::HandleEvent(const char* name, Object** location) {
808
  if (!log_->IsEnabled() || !FLAG_log_handles) return;
809
  Log::MessageBuilder msg(log_);
810
  msg.Append("%s,%p", name, static_cast<void*>(location));
811
  msg.WriteToLogFile();
812 813 814 815
}


// ApiEvent is private so all the calls come from the Logger class.  It is the
816
// caller's responsibility to ensure that log is enabled and that
817 818
// FLAG_log_api is true.
void Logger::ApiEvent(const char* format, ...) {
819
  DCHECK(log_->IsEnabled() && FLAG_log_api);
820
  Log::MessageBuilder msg(log_);
821 822
  va_list ap;
  va_start(ap, format);
823
  msg.AppendVA(format, ap);
824 825
  va_end(ap);
  msg.WriteToLogFile();
826 827 828
}


829
void Logger::ApiSecurityCheck() {
830
  if (!log_->IsEnabled() || !FLAG_log_api) return;
831
  ApiEvent("api,check-security");
832 833
}

834
void Logger::SharedLibraryEvent(const std::string& library_path,
835 836
                                uintptr_t start, uintptr_t end,
                                intptr_t aslr_slide) {
jkummerow's avatar
jkummerow committed
837
  if (!log_->IsEnabled() || !FLAG_prof_cpp) return;
838
  Log::MessageBuilder msg(log_);
839 840 841
  msg.Append("shared-library,\"%s\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR
             ",%" V8PRIdPTR,
             library_path.c_str(), start, end, aslr_slide);
842
  msg.WriteToLogFile();
843 844
}

845

846
void Logger::CodeDeoptEvent(Code* code, Address pc, int fp_to_sp_delta) {
847
  if (!log_->IsEnabled() || !FLAG_log_internal_timer_events) return;
848
  Log::MessageBuilder msg(log_);
849
  int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());
jfb's avatar
jfb committed
850
  msg.Append("code-deopt,%d,%d", since_epoch, code->CodeSize());
851 852 853 854
  msg.WriteToLogFile();
}


855 856
void Logger::CurrentTimeEvent() {
  if (!log_->IsEnabled()) return;
857
  DCHECK(FLAG_log_timer_events || FLAG_prof_cpp);
858 859
  Log::MessageBuilder msg(log_);
  int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());
jfb's avatar
jfb committed
860
  msg.Append("current-time,%d", since_epoch);
861 862 863 864
  msg.WriteToLogFile();
}


865
void Logger::TimerEvent(Logger::StartEnd se, const char* name) {
866
  if (!log_->IsEnabled()) return;
867
  DCHECK(FLAG_log_internal_timer_events);
868
  Log::MessageBuilder msg(log_);
869
  int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());
870 871
  const char* format = (se == START) ? "timer-event-start,\"%s\",%ld"
                                     : "timer-event-end,\"%s\",%ld";
872
  msg.Append(format, name, since_epoch);
873 874 875 876
  msg.WriteToLogFile();
}


877
void Logger::EnterExternal(Isolate* isolate) {
878
  LOG(isolate, TimerEvent(START, TimerEventExternal::name()));
879
  DCHECK(isolate->current_vm_state() == JS);
880
  isolate->set_current_vm_state(EXTERNAL);
881 882 883
}


884
void Logger::LeaveExternal(Isolate* isolate) {
885
  LOG(isolate, TimerEvent(END, TimerEventExternal::name()));
886
  DCHECK(isolate->current_vm_state() == EXTERNAL);
887
  isolate->set_current_vm_state(JS);
888 889
}

890 891 892 893 894 895
// Instantiate template methods.
#define V(TimerName, expose)                                           \
  template void TimerEventScope<TimerEvent##TimerName>::LogTimerEvent( \
      Logger::StartEnd se);
TIMER_EVENTS_LIST(V)
#undef V
896

897 898 899
void Logger::ApiNamedPropertyAccess(const char* tag,
                                    JSObject* holder,
                                    Object* name) {
900
  DCHECK(name->IsName());
901
  if (!log_->IsEnabled() || !FLAG_log_api) return;
902
  String* class_name_obj = holder->class_name();
903
  std::unique_ptr<char[]> class_name =
904
      class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
905
  if (name->IsString()) {
906
    std::unique_ptr<char[]> property_name =
907
        String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
908
    ApiEvent("api,%s,\"%s\",\"%s\"", tag, class_name.get(),
909
             property_name.get());
910
  } else {
911 912
    Symbol* symbol = Symbol::cast(name);
    uint32_t hash = symbol->Hash();
913
    if (symbol->name()->IsUndefined(symbol->GetIsolate())) {
914
      ApiEvent("api,%s,\"%s\",symbol(hash %x)", tag, class_name.get(), hash);
915
    } else {
916
      std::unique_ptr<char[]> str =
rmcilroy's avatar
rmcilroy committed
917 918
          String::cast(symbol->name())
              ->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
919 920
      ApiEvent("api,%s,\"%s\",symbol(\"%s\" hash %x)", tag, class_name.get(),
               str.get(), hash);
921
    }
922
  }
923 924 925 926 927
}

void Logger::ApiIndexedPropertyAccess(const char* tag,
                                      JSObject* holder,
                                      uint32_t index) {
928
  if (!log_->IsEnabled() || !FLAG_log_api) return;
929
  String* class_name_obj = holder->class_name();
930
  std::unique_ptr<char[]> class_name =
931
      class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
932
  ApiEvent("api,%s,\"%s\",%u", tag, class_name.get(), index);
933 934
}

935

936
void Logger::ApiObjectAccess(const char* tag, JSObject* object) {
937
  if (!log_->IsEnabled() || !FLAG_log_api) return;
938
  String* class_name_obj = object->class_name();
939
  std::unique_ptr<char[]> class_name =
940
      class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
941
  ApiEvent("api,%s,\"%s\"", tag, class_name.get());
942 943 944 945
}


void Logger::ApiEntryCall(const char* name) {
946
  if (!log_->IsEnabled() || !FLAG_log_api) return;
947
  ApiEvent("api,%s", name);
948 949 950 951
}


void Logger::NewEvent(const char* name, void* object, size_t size) {
952
  if (!log_->IsEnabled() || !FLAG_log) return;
953
  Log::MessageBuilder msg(log_);
jfb's avatar
jfb committed
954
  msg.Append("new,%s,%p,%u", name, object, static_cast<unsigned int>(size));
955
  msg.WriteToLogFile();
956 957 958 959
}


void Logger::DeleteEvent(const char* name, void* object) {
960
  if (!log_->IsEnabled() || !FLAG_log) return;
961
  Log::MessageBuilder msg(log_);
jfb's avatar
jfb committed
962
  msg.Append("delete,%s,%p", name, object);
963
  msg.WriteToLogFile();
964 965 966
}


967
void Logger::CallbackEventInternal(const char* prefix, Name* name,
968
                                   Address entry_point) {
969
  if (!FLAG_log_code || !log_->IsEnabled()) return;
970
  Log::MessageBuilder msg(log_);
971
  msg.Append("%s,%s,-2,",
972 973
             kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT],
             kLogEventsNames[CodeEventListener::CALLBACK_TAG]);
974
  msg.AppendAddress(entry_point);
975
  if (name->IsString()) {
976
    std::unique_ptr<char[]> str =
977
        String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
978
    msg.Append(",1,\"%s%s\"", prefix, str.get());
979
  } else {
980
    Symbol* symbol = Symbol::cast(name);
981
    if (symbol->name()->IsUndefined(symbol->GetIsolate())) {
jfb's avatar
jfb committed
982
      msg.Append(",1,symbol(hash %x)", symbol->Hash());
983
    } else {
984
      std::unique_ptr<char[]> str =
rmcilroy's avatar
rmcilroy committed
985 986
          String::cast(symbol->name())
              ->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
jfb's avatar
jfb committed
987
      msg.Append(",1,symbol(\"%s%s\" hash %x)", prefix, str.get(),
988
                 symbol->Hash());
989
    }
990
  }
991
  msg.WriteToLogFile();
992 993 994
}


995 996
void Logger::CallbackEvent(Name* name, Address entry_point) {
  CallbackEventInternal("", name, entry_point);
997 998 999
}


1000 1001
void Logger::GetterCallbackEvent(Name* name, Address entry_point) {
  CallbackEventInternal("get ", name, entry_point);
1002 1003 1004
}


1005 1006
void Logger::SetterCallbackEvent(Name* name, Address entry_point) {
  CallbackEventInternal("set ", name, entry_point);
1007 1008
}

1009
static void AppendCodeCreateHeader(Log::MessageBuilder* msg,
1010
                                   CodeEventListener::LogEventsAndTags tag,
1011
                                   AbstractCode* code) {
1012
  DCHECK(msg);
1013
  msg->Append("%s,%s,%d,",
1014 1015
              kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT],
              kLogEventsNames[tag], code->kind());
1016 1017 1018 1019
  msg->AppendAddress(code->address());
  msg->Append(",%d,", code->ExecutableSize());
}

1020 1021
void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
                             AbstractCode* code, const char* comment) {
1022
  if (!is_logging_code_events()) return;
1023
  if (!FLAG_log_code || !log_->IsEnabled()) return;
1024
  Log::MessageBuilder msg(log_);
1025 1026
  AppendCodeCreateHeader(&msg, tag, code);
  msg.AppendDoubleQuotedString(comment);
1027
  msg.WriteToLogFile();
1028 1029
}

1030 1031
void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
                             AbstractCode* code, Name* name) {
1032
  if (!is_logging_code_events()) return;
1033
  if (!FLAG_log_code || !log_->IsEnabled()) return;
1034
  Log::MessageBuilder msg(log_);
1035
  AppendCodeCreateHeader(&msg, tag, code);
1036 1037 1038 1039 1040
  if (name->IsString()) {
    msg.Append('"');
    msg.AppendDetailed(String::cast(name), false);
    msg.Append('"');
  } else {
1041
    msg.AppendSymbolName(Symbol::cast(name));
1042
  }
1043
  msg.WriteToLogFile();
1044 1045
}

1046 1047 1048
void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
                             AbstractCode* code, SharedFunctionInfo* shared,
                             Name* name) {
1049
  if (!is_logging_code_events()) return;
1050
  if (!FLAG_log_code || !log_->IsEnabled()) return;
1051 1052 1053 1054
  if (code == AbstractCode::cast(
                  isolate_->builtins()->builtin(Builtins::kCompileLazy))) {
    return;
  }
1055

1056
  Log::MessageBuilder msg(log_);
1057
  AppendCodeCreateHeader(&msg, tag, code);
1058
  if (name->IsString()) {
1059
    std::unique_ptr<char[]> str =
1060
        String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
1061
    msg.Append("\"%s\"", str.get());
1062
  } else {
1063
    msg.AppendSymbolName(Symbol::cast(name));
1064 1065
  }
  msg.Append(',');
1066
  msg.AppendAddress(shared->address());
1067
  msg.Append(",%s", ComputeMarker(shared, code));
1068
  msg.WriteToLogFile();
1069 1070 1071
}


1072 1073 1074
// Although, it is possible to extract source and line from
// the SharedFunctionInfo object, we left it to caller
// to leave logging functions free from heap allocations.
1075 1076 1077
void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
                             AbstractCode* code, SharedFunctionInfo* shared,
                             Name* source, int line, int column) {
1078
  if (!is_logging_code_events()) return;
1079
  if (!FLAG_log_code || !log_->IsEnabled()) return;
1080
  Log::MessageBuilder msg(log_);
1081
  AppendCodeCreateHeader(&msg, tag, code);
1082
  std::unique_ptr<char[]> name =
1083
      shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
1084
  msg.Append("\"%s ", name.get());
1085
  if (source->IsString()) {
1086
    std::unique_ptr<char[]> sourcestr = String::cast(source)->ToCString(
rmcilroy's avatar
rmcilroy committed
1087
        DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
1088
    msg.Append("%s", sourcestr.get());
1089
  } else {
1090
    msg.AppendSymbolName(Symbol::cast(source));
1091
  }
1092
  msg.Append(":%d:%d\",", line, column);
1093
  msg.AppendAddress(shared->address());
1094
  msg.Append(",%s", ComputeMarker(shared, code));
1095
  msg.WriteToLogFile();
1096 1097
}

1098 1099
void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
                             AbstractCode* code, int args_count) {
1100
  if (!is_logging_code_events()) return;
1101
  if (!FLAG_log_code || !log_->IsEnabled()) return;
1102
  Log::MessageBuilder msg(log_);
1103 1104
  AppendCodeCreateHeader(&msg, tag, code);
  msg.Append("\"args_count: %d\"", args_count);
1105
  msg.WriteToLogFile();
1106 1107
}

1108
void Logger::CodeDisableOptEvent(AbstractCode* code,
1109 1110 1111 1112
                                 SharedFunctionInfo* shared) {
  if (!is_logging_code_events()) return;
  if (!FLAG_log_code || !log_->IsEnabled()) return;
  Log::MessageBuilder msg(log_);
1113
  msg.Append("%s,", kLogEventsNames[CodeEventListener::CODE_DISABLE_OPT_EVENT]);
1114
  std::unique_ptr<char[]> name =
1115 1116
      shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
  msg.Append("\"%s\",", name.get());
1117
  msg.Append("\"%s\"", GetBailoutReason(shared->disable_optimization_reason()));
1118 1119 1120 1121
  msg.WriteToLogFile();
}


1122
void Logger::CodeMovingGCEvent() {
1123
  if (!is_logging_code_events()) return;
1124
  if (!log_->IsEnabled() || !FLAG_ll_prof) return;
1125
  base::OS::SignalCodeMovingGC();
1126 1127
}

1128
void Logger::RegExpCodeCreateEvent(AbstractCode* code, String* source) {
1129
  if (!is_logging_code_events()) return;
1130
  if (!FLAG_log_code || !log_->IsEnabled()) return;
1131
  Log::MessageBuilder msg(log_);
1132
  AppendCodeCreateHeader(&msg, CodeEventListener::REG_EXP_TAG, code);
1133
  msg.Append('"');
1134
  msg.AppendDetailed(source, false);
1135
  msg.Append('"');
1136 1137 1138
  msg.WriteToLogFile();
}

1139
void Logger::CodeMoveEvent(AbstractCode* from, Address to) {
1140
  if (!is_logging_code_events()) return;
1141
  MoveEventInternal(CodeEventListener::CODE_MOVE_EVENT, from->address(), to);
1142 1143
}

1144 1145 1146 1147 1148 1149 1150 1151
void Logger::CodeLinePosInfoRecordEvent(AbstractCode* code,
                                        ByteArray* source_position_table) {
  if (jit_logger_) {
    void* jit_handler_data = jit_logger_->StartCodePosInfoEvent();
    for (SourcePositionTableIterator iter(source_position_table); !iter.done();
         iter.Advance()) {
      if (iter.is_statement()) {
        jit_logger_->AddCodeLinePosInfoEvent(
1152 1153
            jit_handler_data, iter.code_offset(),
            iter.source_position().ScriptOffset(),
1154 1155
            JitCodeEvent::STATEMENT_POSITION);
      }
1156 1157 1158
      jit_logger_->AddCodeLinePosInfoEvent(
          jit_handler_data, iter.code_offset(),
          iter.source_position().ScriptOffset(), JitCodeEvent::POSITION);
1159 1160 1161
    }
    jit_logger_->EndCodePosInfoEvent(code, jit_handler_data);
  }
1162
}
1163

1164 1165 1166
void Logger::CodeNameEvent(Address addr, int pos, const char* code_name) {
  if (code_name == NULL) return;  // Not a code object.
  Log::MessageBuilder msg(log_);
1167 1168
  msg.Append("%s,%d,",
             kLogEventsNames[CodeEventListener::SNAPSHOT_CODE_NAME_EVENT], pos);
1169 1170 1171 1172
  msg.AppendDoubleQuotedString(code_name);
  msg.WriteToLogFile();
}

1173

1174
void Logger::SharedFunctionInfoMoveEvent(Address from, Address to) {
1175
  if (!is_logging_code_events()) return;
1176
  MoveEventInternal(CodeEventListener::SHARED_FUNC_MOVE_EVENT, from, to);
1177 1178
}

1179 1180
void Logger::MoveEventInternal(CodeEventListener::LogEventsAndTags event,
                               Address from, Address to) {
1181
  if (!FLAG_log_code || !log_->IsEnabled()) return;
1182
  Log::MessageBuilder msg(log_);
1183
  msg.Append("%s,", kLogEventsNames[event]);
1184
  msg.AppendAddress(from);
1185
  msg.Append(',');
1186
  msg.AppendAddress(to);
1187
  msg.WriteToLogFile();
1188 1189 1190
}


1191
void Logger::ResourceEvent(const char* name, const char* tag) {
1192
  if (!log_->IsEnabled() || !FLAG_log) return;
1193
  Log::MessageBuilder msg(log_);
1194
  msg.Append("%s,%s,", name, tag);
1195 1196

  uint32_t sec, usec;
1197
  if (base::OS::GetUserTime(&sec, &usec) != -1) {
1198
    msg.Append("%d,%d,", sec, usec);
1199
  }
1200
  msg.Append("%.0f", base::OS::TimeCurrentMillis());
1201
  msg.WriteToLogFile();
1202 1203 1204
}


1205
void Logger::SuspectReadEvent(Name* name, Object* obj) {
1206
  if (!log_->IsEnabled() || !FLAG_log_suspect) return;
1207
  Log::MessageBuilder msg(log_);
1208 1209
  String* class_name = obj->IsJSObject()
                       ? JSObject::cast(obj)->class_name()
1210
                       : isolate_->heap()->empty_string();
1211 1212 1213
  msg.Append("suspect-read,");
  msg.Append(class_name);
  msg.Append(',');
1214 1215 1216 1217 1218
  if (name->IsString()) {
    msg.Append('"');
    msg.Append(String::cast(name));
    msg.Append('"');
  } else {
1219
    msg.AppendSymbolName(Symbol::cast(name));
1220
  }
1221
  msg.WriteToLogFile();
1222 1223 1224 1225
}


void Logger::HeapSampleBeginEvent(const char* space, const char* kind) {
1226
  if (!log_->IsEnabled() || !FLAG_log_gc) return;
1227
  Log::MessageBuilder msg(log_);
1228 1229
  // Using non-relative system time in order to be able to synchronize with
  // external memory profiling events (e.g. DOM memory size).
1230 1231
  msg.Append("heap-sample-begin,\"%s\",\"%s\",%.0f", space, kind,
             base::OS::TimeCurrentMillis());
1232 1233 1234 1235
  msg.WriteToLogFile();
}


1236
void Logger::HeapSampleEndEvent(const char* space, const char* kind) {
1237
  if (!log_->IsEnabled() || !FLAG_log_gc) return;
1238
  Log::MessageBuilder msg(log_);
1239
  msg.Append("heap-sample-end,\"%s\",\"%s\"", space, kind);
1240
  msg.WriteToLogFile();
1241 1242 1243 1244
}


void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) {
1245
  if (!log_->IsEnabled() || !FLAG_log_gc) return;
1246
  Log::MessageBuilder msg(log_);
1247
  msg.Append("heap-sample-item,%s,%d,%d", type, number, bytes);
1248
  msg.WriteToLogFile();
1249 1250 1251
}


1252 1253 1254 1255 1256 1257 1258 1259
void Logger::RuntimeCallTimerEvent() {
  RuntimeCallStats* stats = isolate_->counters()->runtime_call_stats();
  RuntimeCallTimer* timer = stats->current_timer();
  if (timer == nullptr) return;
  RuntimeCallCounter* counter = timer->counter();
  if (counter == nullptr) return;
  Log::MessageBuilder msg(log_);
  msg.Append("active-runtime-timer,");
1260
  msg.AppendDoubleQuotedString(counter->name());
1261 1262
  msg.WriteToLogFile();
}
1263

1264
void Logger::TickEvent(v8::TickSample* sample, bool overflow) {
jkummerow's avatar
jkummerow committed
1265
  if (!log_->IsEnabled() || !FLAG_prof_cpp) return;
1266 1267
  if (V8_UNLIKELY(FLAG_runtime_stats ==
                  v8::tracing::TracingCategoryObserver::ENABLED_BY_NATIVE)) {
1268 1269
    RuntimeCallTimerEvent();
  }
1270
  Log::MessageBuilder msg(log_);
1271
  msg.Append("%s,", kLogEventsNames[CodeEventListener::TICK_EVENT]);
1272
  msg.AppendAddress(reinterpret_cast<Address>(sample->pc));
jfb's avatar
jfb committed
1273
  msg.Append(",%d", static_cast<int>(timer_.Elapsed().InMicroseconds()));
1274 1275
  if (sample->has_external_callback) {
    msg.Append(",1,");
1276 1277
    msg.AppendAddress(
        reinterpret_cast<Address>(sample->external_callback_entry));
1278 1279
  } else {
    msg.Append(",0,");
1280
    msg.AppendAddress(reinterpret_cast<Address>(sample->tos));
1281
  }
1282
  msg.Append(",%d", static_cast<int>(sample->state));
1283 1284 1285
  if (overflow) {
    msg.Append(",overflow");
  }
1286
  for (unsigned i = 0; i < sample->frames_count; ++i) {
1287
    msg.Append(',');
1288
    msg.AppendAddress(reinterpret_cast<Address>(sample->stack[i]));
1289
  }
1290
  msg.WriteToLogFile();
1291
}
1292 1293


1294
void Logger::StopProfiler() {
1295
  if (!log_->IsEnabled()) return;
1296
  if (profiler_ != NULL) {
1297 1298
    profiler_->pause();
    is_logging_ = false;
1299
    removeCodeEventListener(this);
1300
  }
1301
}
1302 1303


1304 1305
// This function can be called when Log's mutex is acquired,
// either from main or Profiler's thread.
1306
void Logger::LogFailure() {
1307
  StopProfiler();
1308 1309
}

1310 1311 1312 1313 1314 1315 1316 1317 1318 1319 1320
static void AddFunctionAndCode(SharedFunctionInfo* sfi,
                               AbstractCode* code_object,
                               Handle<SharedFunctionInfo>* sfis,
                               Handle<AbstractCode>* code_objects, int offset) {
  if (sfis != NULL) {
    sfis[offset] = Handle<SharedFunctionInfo>(sfi);
  }
  if (code_objects != NULL) {
    code_objects[offset] = Handle<AbstractCode>(code_object);
  }
}
1321

1322 1323 1324
class EnumerateOptimizedFunctionsVisitor: public OptimizedFunctionVisitor {
 public:
  EnumerateOptimizedFunctionsVisitor(Handle<SharedFunctionInfo>* sfis,
1325
                                     Handle<AbstractCode>* code_objects,
1326
                                     int* count)
1327
      : sfis_(sfis), code_objects_(code_objects), count_(count) {}
1328 1329 1330 1331 1332

  virtual void EnterContext(Context* context) {}
  virtual void LeaveContext(Context* context) {}

  virtual void VisitFunction(JSFunction* function) {
1333 1334 1335 1336
    SharedFunctionInfo* sfi = SharedFunctionInfo::cast(function->shared());
    Object* maybe_script = sfi->script();
    if (maybe_script->IsScript()
        && !Script::cast(maybe_script)->HasValidSource()) return;
1337 1338 1339 1340 1341

    DCHECK(function->abstract_code()->kind() ==
           AbstractCode::OPTIMIZED_FUNCTION);
    AddFunctionAndCode(sfi, function->abstract_code(), sfis_, code_objects_,
                       *count_);
1342 1343 1344 1345 1346
    *count_ = *count_ + 1;
  }

 private:
  Handle<SharedFunctionInfo>* sfis_;
1347
  Handle<AbstractCode>* code_objects_;
1348 1349 1350
  int* count_;
};

1351 1352
static int EnumerateCompiledFunctions(Heap* heap,
                                      Handle<SharedFunctionInfo>* sfis,
1353
                                      Handle<AbstractCode>* code_objects) {
1354
  HeapIterator iterator(heap);
1355
  DisallowHeapAllocation no_gc;
1356
  int compiled_funcs_count = 0;
1357 1358 1359

  // Iterate the heap to find shared function info objects and record
  // the unoptimized code for them.
1360
  for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
1361 1362 1363 1364 1365
    if (!obj->IsSharedFunctionInfo()) continue;
    SharedFunctionInfo* sfi = SharedFunctionInfo::cast(obj);
    if (sfi->is_compiled()
        && (!sfi->script()->IsScript()
            || Script::cast(sfi->script())->HasValidSource())) {
1366 1367 1368 1369 1370 1371
      // In some cases, an SFI might have (and have executing!) both bytecode
      // and baseline code, so check for both and add them both if needed.
      if (sfi->HasBytecodeArray()) {
        AddFunctionAndCode(sfi, AbstractCode::cast(sfi->bytecode_array()), sfis,
                           code_objects, compiled_funcs_count);
        ++compiled_funcs_count;
1372
      }
1373 1374 1375 1376 1377

      if (!sfi->IsInterpreted()) {
        AddFunctionAndCode(sfi, AbstractCode::cast(sfi->code()), sfis,
                           code_objects, compiled_funcs_count);
        ++compiled_funcs_count;
1378
      }
1379
    }
1380
  }
1381 1382 1383 1384 1385

  // Iterate all optimized functions in all contexts.
  EnumerateOptimizedFunctionsVisitor visitor(sfis,
                                             code_objects,
                                             &compiled_funcs_count);
1386
  Deoptimizer::VisitAllOptimizedFunctions(heap->isolate(), &visitor);
1387

1388 1389
  return compiled_funcs_count;
}
1390 1391


1392
void Logger::LogCodeObject(Object* object) {
1393
  AbstractCode* code_object = AbstractCode::cast(object);
1394
  CodeEventListener::LogEventsAndTags tag = CodeEventListener::STUB_TAG;
1395 1396
  const char* description = "Unknown code from the snapshot";
  switch (code_object->kind()) {
1397 1398 1399
    case AbstractCode::FUNCTION:
    case AbstractCode::INTERPRETED_FUNCTION:
    case AbstractCode::OPTIMIZED_FUNCTION:
1400
      return;  // We log this later using LogCompiledFunctions.
1401 1402
    case AbstractCode::BYTECODE_HANDLER:
      return;  // We log it later by walking the dispatch table.
1403 1404 1405 1406 1407 1408 1409
    case AbstractCode::BINARY_OP_IC:    // fall through
    case AbstractCode::COMPARE_IC:      // fall through
    case AbstractCode::TO_BOOLEAN_IC:   // fall through

    case AbstractCode::STUB:
      description =
          CodeStub::MajorName(CodeStub::GetMajorKey(code_object->GetCode()));
1410 1411
      if (description == NULL)
        description = "A stub from the snapshot";
1412
      tag = CodeEventListener::STUB_TAG;
1413
      break;
1414
    case AbstractCode::REGEXP:
1415
      description = "Regular expression code";
1416
      tag = CodeEventListener::REG_EXP_TAG;
1417
      break;
1418 1419 1420
    case AbstractCode::BUILTIN:
      description =
          isolate_->builtins()->name(code_object->GetCode()->builtin_index());
1421
      tag = CodeEventListener::BUILTIN_TAG;
1422
      break;
1423
    case AbstractCode::HANDLER:
1424
      description = "An IC handler from the snapshot";
1425
      tag = CodeEventListener::HANDLER_TAG;
1426
      break;
1427
    case AbstractCode::KEYED_LOAD_IC:
1428
      description = "A keyed load IC from the snapshot";
1429
      tag = CodeEventListener::KEYED_LOAD_IC_TAG;
1430
      break;
1431
    case AbstractCode::LOAD_IC:
1432
      description = "A load IC from the snapshot";
1433
      tag = CodeEventListener::LOAD_IC_TAG;
1434
      break;
1435 1436 1437 1438
    case AbstractCode::LOAD_GLOBAL_IC:
      description = "A load global IC from the snapshot";
      tag = Logger::LOAD_GLOBAL_IC_TAG;
      break;
1439
    case AbstractCode::CALL_IC:
1440
      description = "A call IC from the snapshot";
1441
      tag = CodeEventListener::CALL_IC_TAG;
1442
      break;
1443
    case AbstractCode::STORE_IC:
1444
      description = "A store IC from the snapshot";
1445
      tag = CodeEventListener::STORE_IC_TAG;
1446
      break;
1447
    case AbstractCode::KEYED_STORE_IC:
1448
      description = "A keyed store IC from the snapshot";
1449
      tag = CodeEventListener::KEYED_STORE_IC_TAG;
1450
      break;
1451
    case AbstractCode::WASM_FUNCTION:
1452
      description = "A Wasm function";
1453
      tag = CodeEventListener::STUB_TAG;
1454 1455 1456
      break;
    case AbstractCode::JS_TO_WASM_FUNCTION:
      description = "A JavaScript to Wasm adapter";
1457
      tag = CodeEventListener::STUB_TAG;
1458 1459 1460
      break;
    case AbstractCode::WASM_TO_JS_FUNCTION:
      description = "A Wasm to JavaScript adapter";
1461
      tag = CodeEventListener::STUB_TAG;
titzer's avatar
titzer committed
1462
      break;
1463 1464 1465 1466
    case AbstractCode::WASM_INTERPRETER_ENTRY:
      description = "A Wasm to Interpreter adapter";
      tag = CodeEventListener::STUB_TAG;
      break;
1467 1468
    case AbstractCode::NUMBER_OF_KINDS:
      UNIMPLEMENTED();
1469
  }
1470
  PROFILE(isolate_, CodeCreateEvent(tag, code_object, description));
1471 1472 1473
}


1474
void Logger::LogCodeObjects() {
1475
  Heap* heap = isolate_->heap();
1476
  HeapIterator iterator(heap);
1477
  DisallowHeapAllocation no_gc;
1478 1479
  for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
    if (obj->IsCode()) LogCodeObject(obj);
1480
    if (obj->IsBytecodeArray()) LogCodeObject(obj);
1481 1482 1483
  }
}

1484
void Logger::LogBytecodeHandlers() {
1485 1486 1487 1488 1489 1490
  const interpreter::OperandScale kOperandScales[] = {
#define VALUE(Name, _) interpreter::OperandScale::k##Name,
      OPERAND_SCALE_LIST(VALUE)
#undef VALUE
  };

1491
  const int last_index = static_cast<int>(interpreter::Bytecode::kLast);
1492 1493
  interpreter::Interpreter* interpreter = isolate_->interpreter();
  for (auto operand_scale : kOperandScales) {
1494 1495
    for (int index = 0; index <= last_index; ++index) {
      interpreter::Bytecode bytecode = interpreter::Bytecodes::FromByte(index);
1496
      if (interpreter::Bytecodes::BytecodeHasHandler(bytecode, operand_scale)) {
1497 1498 1499
        Code* code = interpreter->GetBytecodeHandler(bytecode, operand_scale);
        std::string bytecode_name =
            interpreter::Bytecodes::ToString(bytecode, operand_scale);
1500 1501 1502
        PROFILE(isolate_, CodeCreateEvent(
                              CodeEventListener::BYTECODE_HANDLER_TAG,
                              AbstractCode::cast(code), bytecode_name.c_str()));
1503 1504
      }
    }
1505 1506 1507
  }
}

1508
void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared,
1509
                                 Handle<AbstractCode> code) {
1510 1511
  if (shared->script()->IsScript()) {
    Handle<Script> script(Script::cast(shared->script()));
1512
    int line_num = Script::GetLineNumber(script, shared->start_position()) + 1;
1513
    int column_num =
1514
        Script::GetColumnNumber(script, shared->start_position()) + 1;
1515
    if (script->name()->IsString()) {
1516 1517
      Handle<String> script_name(String::cast(script->name()));
      if (line_num > 0) {
1518
        PROFILE(isolate_,
1519
                CodeCreateEvent(
1520 1521
                    Logger::ToNativeByScript(
                        CodeEventListener::LAZY_COMPILE_TAG, *script),
1522
                    *code, *shared, *script_name, line_num, column_num));
1523 1524
      } else {
        // Can't distinguish eval and script here, so always use Script.
1525 1526 1527 1528
        PROFILE(isolate_,
                CodeCreateEvent(Logger::ToNativeByScript(
                                    CodeEventListener::SCRIPT_TAG, *script),
                                *code, *shared, *script_name));
1529 1530
      }
    } else {
1531
      PROFILE(isolate_,
1532 1533 1534 1535
              CodeCreateEvent(Logger::ToNativeByScript(
                                  CodeEventListener::LAZY_COMPILE_TAG, *script),
                              *code, *shared, isolate_->heap()->empty_string(),
                              line_num, column_num));
1536 1537 1538 1539 1540
    }
  } else if (shared->IsApiFunction()) {
    // API function.
    FunctionTemplateInfo* fun_data = shared->get_api_func_data();
    Object* raw_call_data = fun_data->call_code();
1541
    if (!raw_call_data->IsUndefined(isolate_)) {
1542 1543 1544
      CallHandlerInfo* call_data = CallHandlerInfo::cast(raw_call_data);
      Object* callback_obj = call_data->callback();
      Address entry_point = v8::ToCData<Address>(callback_obj);
1545 1546 1547
#if USES_FUNCTION_DESCRIPTORS
      entry_point = *FUNCTION_ENTRYPOINT_ADDRESS(entry_point);
#endif
1548
      PROFILE(isolate_, CallbackEvent(shared->DebugName(), entry_point));
1549 1550
    }
  } else {
1551 1552 1553
    PROFILE(isolate_,
            CodeCreateEvent(CodeEventListener::LAZY_COMPILE_TAG, *code, *shared,
                            isolate_->heap()->empty_string()));
1554 1555 1556 1557
  }
}


1558
void Logger::LogCompiledFunctions() {
1559 1560
  Heap* heap = isolate_->heap();
  HandleScope scope(isolate_);
1561
  const int compiled_funcs_count = EnumerateCompiledFunctions(heap, NULL, NULL);
1562
  ScopedVector< Handle<SharedFunctionInfo> > sfis(compiled_funcs_count);
1563
  ScopedVector<Handle<AbstractCode> > code_objects(compiled_funcs_count);
1564
  EnumerateCompiledFunctions(heap, sfis.start(), code_objects.start());
1565 1566 1567 1568

  // During iteration, there can be heap allocation due to
  // GetScriptLineNumber call.
  for (int i = 0; i < compiled_funcs_count; ++i) {
1569
    if (code_objects[i].is_identical_to(isolate_->builtins()->CompileLazy()))
1570
      continue;
1571
    LogExistingFunction(sfis[i], code_objects[i]);
1572 1573 1574
  }
}

1575 1576

void Logger::LogAccessorCallbacks() {
1577
  Heap* heap = isolate_->heap();
1578
  HeapIterator iterator(heap);
1579
  DisallowHeapAllocation no_gc;
1580
  for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
1581 1582
    if (!obj->IsAccessorInfo()) continue;
    AccessorInfo* ai = AccessorInfo::cast(obj);
1583
    if (!ai->name()->IsName()) continue;
1584
    Address getter_entry = v8::ToCData<Address>(ai->getter());
1585
    Name* name = Name::cast(ai->name());
1586
    if (getter_entry != 0) {
1587 1588 1589
#if USES_FUNCTION_DESCRIPTORS
      getter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(getter_entry);
#endif
1590
      PROFILE(isolate_, GetterCallbackEvent(name, getter_entry));
1591 1592 1593
    }
    Address setter_entry = v8::ToCData<Address>(ai->setter());
    if (setter_entry != 0) {
1594 1595 1596
#if USES_FUNCTION_DESCRIPTORS
      setter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(setter_entry);
#endif
1597
      PROFILE(isolate_, SetterCallbackEvent(name, setter_entry));
1598 1599 1600 1601
    }
  }
}

1602

1603
static void AddIsolateIdIfNeeded(std::ostream& os,  // NOLINT
1604 1605
                                 Isolate* isolate) {
  if (FLAG_logfile_per_isolate) os << "isolate-" << isolate << "-";
1606 1607 1608
}


1609
static void PrepareLogFileName(std::ostream& os,  // NOLINT
1610
                               Isolate* isolate, const char* file_name) {
sejunho's avatar
sejunho committed
1611
  int dir_separator_count = 0;
1612
  for (const char* p = file_name; *p; p++) {
sejunho's avatar
sejunho committed
1613 1614 1615 1616 1617 1618 1619 1620
    if (base::OS::isDirectorySeparator(*p)) dir_separator_count++;
  }

  for (const char* p = file_name; *p; p++) {
    if (dir_separator_count == 0) {
      AddIsolateIdIfNeeded(os, isolate);
      dir_separator_count--;
    }
1621 1622 1623 1624 1625 1626 1627 1628 1629
    if (*p == '%') {
      p++;
      switch (*p) {
        case '\0':
          // If there's a % at the end of the string we back up
          // one character so we can escape the loop properly.
          p--;
          break;
        case 'p':
1630
          os << base::OS::GetCurrentProcessId();
1631
          break;
1632
        case 't':
1633
          // %t expands to the current time in milliseconds.
1634
          os << static_cast<int64_t>(base::OS::TimeCurrentMillis());
1635 1636 1637
          break;
        case '%':
          // %% expands (contracts really) to %.
1638
          os << '%';
1639 1640 1641
          break;
        default:
          // All other %'s expand to themselves.
1642
          os << '%' << *p;
1643
          break;
1644
      }
1645
    } else {
sejunho's avatar
sejunho committed
1646
      if (base::OS::isDirectorySeparator(*p)) dir_separator_count--;
1647
      os << *p;
1648 1649 1650 1651 1652
    }
  }
}


1653
bool Logger::SetUp(Isolate* isolate) {
1654 1655 1656
  // Tests and EnsureInitialize() can call this twice in a row. It's harmless.
  if (is_initialized_) return true;
  is_initialized_ = true;
1657

1658
  std::ostringstream log_file_name;
1659
  PrepareLogFileName(log_file_name, isolate, FLAG_logfile);
1660
  log_->Initialize(log_file_name.str().c_str());
1661

1662 1663 1664 1665 1666
  if (FLAG_perf_basic_prof) {
    perf_basic_logger_ = new PerfBasicLogger();
    addCodeEventListener(perf_basic_logger_);
  }

1667 1668 1669 1670 1671
  if (FLAG_perf_prof) {
    perf_jit_logger_ = new PerfJitLogger();
    addCodeEventListener(perf_jit_logger_);
  }

1672
  if (FLAG_ll_prof) {
1673
    ll_logger_ = new LowLevelLogger(log_file_name.str().c_str());
1674
    addCodeEventListener(ll_logger_);
1675
  }
1676

1677 1678
  ticker_ = new Ticker(isolate, kSamplingIntervalMs);

1679
  if (Log::InitLogAtStart()) {
1680
    is_logging_ = true;
1681
  }
1682

jkummerow's avatar
jkummerow committed
1683
  if (FLAG_log_internal_timer_events || FLAG_prof_cpp) timer_.Start();
1684

jkummerow's avatar
jkummerow committed
1685
  if (FLAG_prof_cpp) {
1686
    profiler_ = new Profiler(isolate);
1687 1688
    is_logging_ = true;
    profiler_->Engage();
1689 1690
  }

lpy's avatar
lpy committed
1691 1692
  profiler_listener_.reset();

1693 1694 1695 1696
  if (is_logging_) {
    addCodeEventListener(this);
  }

1697 1698 1699 1700
  return true;
}


1701 1702
void Logger::SetCodeEventHandler(uint32_t options,
                                 JitCodeEventHandler event_handler) {
1703
  if (jit_logger_) {
1704
      removeCodeEventListener(jit_logger_);
1705 1706 1707
      delete jit_logger_;
      jit_logger_ = NULL;
  }
1708

1709 1710
  if (event_handler) {
    jit_logger_ = new JitLogger(event_handler);
1711 1712 1713 1714 1715 1716
    addCodeEventListener(jit_logger_);
    if (options & kJitCodeEventEnumExisting) {
      HandleScope scope(isolate_);
      LogCodeObjects();
      LogCompiledFunctions();
    }
1717 1718 1719
  }
}

lpy's avatar
lpy committed
1720 1721 1722 1723 1724 1725 1726 1727 1728 1729 1730 1731
void Logger::SetUpProfilerListener() {
  if (!is_initialized_) return;
  if (profiler_listener_.get() == nullptr) {
    profiler_listener_.reset(new ProfilerListener(isolate_));
  }
  addCodeEventListener(profiler_listener_.get());
}

void Logger::TearDownProfilerListener() {
  if (profiler_listener_->HasObservers()) return;
  removeCodeEventListener(profiler_listener_.get());
}
1732

1733
sampler::Sampler* Logger::sampler() {
1734 1735 1736 1737
  return ticker_;
}


1738 1739
FILE* Logger::TearDown() {
  if (!is_initialized_) return NULL;
1740
  is_initialized_ = false;
1741

1742 1743 1744 1745 1746 1747 1748 1749
  // Stop the profiler before closing the file.
  if (profiler_ != NULL) {
    profiler_->Disengage();
    delete profiler_;
    profiler_ = NULL;
  }

  delete ticker_;
1750
  ticker_ = NULL;
1751

1752 1753 1754 1755 1756 1757
  if (perf_basic_logger_) {
    removeCodeEventListener(perf_basic_logger_);
    delete perf_basic_logger_;
    perf_basic_logger_ = NULL;
  }

1758 1759 1760 1761 1762 1763
  if (perf_jit_logger_) {
    removeCodeEventListener(perf_jit_logger_);
    delete perf_jit_logger_;
    perf_jit_logger_ = NULL;
  }

1764
  if (ll_logger_) {
1765
    removeCodeEventListener(ll_logger_);
1766 1767 1768 1769
    delete ll_logger_;
    ll_logger_ = NULL;
  }

1770
  if (jit_logger_) {
1771
    removeCodeEventListener(jit_logger_);
1772 1773 1774 1775
    delete jit_logger_;
    jit_logger_ = NULL;
  }

lpy's avatar
lpy committed
1776 1777 1778 1779
  if (profiler_listener_.get() != nullptr) {
    removeCodeEventListener(profiler_listener_.get());
  }

1780
  return log_->Close();
1781 1782
}

1783 1784
}  // namespace internal
}  // namespace v8