Home | History | Annotate | Download | only in src
      1 // Copyright 2011 the V8 project authors. All rights reserved.
      2 // Use of this source code is governed by a BSD-style license that can be
      3 // found in the LICENSE file.
      4 
      5 #include "src/log.h"
      6 
      7 #include <cstdarg>
      8 #include <memory>
      9 #include <sstream>
     10 
     11 #include "src/api-inl.h"
     12 #include "src/bailout-reason.h"
     13 #include "src/base/platform/platform.h"
     14 #include "src/bootstrapper.h"
     15 #include "src/code-stubs.h"
     16 #include "src/counters.h"
     17 #include "src/deoptimizer.h"
     18 #include "src/global-handles.h"
     19 #include "src/instruction-stream.h"
     20 #include "src/interpreter/bytecodes.h"
     21 #include "src/interpreter/interpreter.h"
     22 #include "src/libsampler/sampler.h"
     23 #include "src/log-inl.h"
     24 #include "src/macro-assembler.h"
     25 #include "src/objects/api-callbacks.h"
     26 #include "src/perf-jit.h"
     27 #include "src/profiler/tick-sample.h"
     28 #include "src/runtime-profiler.h"
     29 #include "src/source-position-table.h"
     30 #include "src/string-stream.h"
     31 #include "src/tracing/tracing-category-observer.h"
     32 #include "src/unicode-inl.h"
     33 #include "src/vm-state-inl.h"
     34 #include "src/wasm/wasm-code-manager.h"
     35 #include "src/wasm/wasm-objects-inl.h"
     36 
     37 #include "src/utils.h"
     38 #include "src/version.h"
     39 
     40 namespace v8 {
     41 namespace internal {
     42 
     43 #define DECLARE_EVENT(ignore1, name) #name,
     44 static const char* kLogEventsNames[CodeEventListener::NUMBER_OF_LOG_EVENTS] = {
     45     LOG_EVENTS_AND_TAGS_LIST(DECLARE_EVENT)};
     46 #undef DECLARE_EVENT
     47 
     48 static v8::CodeEventType GetCodeEventTypeForTag(
     49     CodeEventListener::LogEventsAndTags tag) {
     50   switch (tag) {
     51     case CodeEventListener::NUMBER_OF_LOG_EVENTS:
     52 #define V(Event, _) case CodeEventListener::Event:
     53       LOG_EVENTS_LIST(V)
     54 #undef V
     55       return v8::CodeEventType::kUnknownType;
     56 #define V(From, To)             \
     57   case CodeEventListener::From: \
     58     return v8::CodeEventType::k##To##Type;
     59       TAGS_LIST(V)
     60 #undef V
     61   }
     62   // The execution should never pass here
     63   UNREACHABLE();
     64   // NOTE(mmarchini): Workaround to fix a compiler failure on GCC 4.9
     65   return v8::CodeEventType::kUnknownType;
     66 }
     67 #define CALL_CODE_EVENT_HANDLER(Call) \
     68   if (listener_) {                    \
     69     listener_->Call;                  \
     70   } else {                            \
     71     PROFILE(isolate_, Call);          \
     72   }
     73 
     74 static const char* ComputeMarker(SharedFunctionInfo* shared,
     75                                  AbstractCode* code) {
     76   switch (code->kind()) {
     77     case AbstractCode::INTERPRETED_FUNCTION:
     78       return shared->optimization_disabled() ? "" : "~";
     79     case AbstractCode::OPTIMIZED_FUNCTION:
     80       return "*";
     81     default:
     82       return "";
     83   }
     84 }
     85 
     86 static const char* ComputeMarker(const wasm::WasmCode* code) {
     87   switch (code->kind()) {
     88     case wasm::WasmCode::kFunction:
     89       return code->is_liftoff() ? "" : "*";
     90     case wasm::WasmCode::kInterpreterEntry:
     91       return "~";
     92     default:
     93       return "";
     94   }
     95 }
     96 
     97 class CodeEventLogger::NameBuffer {
     98  public:
     99   NameBuffer() { Reset(); }
    100 
    101   void Reset() {
    102     utf8_pos_ = 0;
    103   }
    104 
    105   void Init(CodeEventListener::LogEventsAndTags tag) {
    106     Reset();
    107     AppendBytes(kLogEventsNames[tag]);
    108     AppendByte(':');
    109   }
    110 
    111   void AppendName(Name* name) {
    112     if (name->IsString()) {
    113       AppendString(String::cast(name));
    114     } else {
    115       Symbol* symbol = Symbol::cast(name);
    116       AppendBytes("symbol(");
    117       if (!symbol->name()->IsUndefined()) {
    118         AppendBytes("\"");
    119         AppendString(String::cast(symbol->name()));
    120         AppendBytes("\" ");
    121       }
    122       AppendBytes("hash ");
    123       AppendHex(symbol->Hash());
    124       AppendByte(')');
    125     }
    126   }
    127 
    128   void AppendString(String* str) {
    129     if (str == nullptr) return;
    130     int length = 0;
    131     std::unique_ptr<char[]> c_str =
    132         str->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL, &length);
    133     AppendBytes(c_str.get(), length);
    134   }
    135 
    136   void AppendBytes(const char* bytes, int size) {
    137     size = Min(size, kUtf8BufferSize - utf8_pos_);
    138     MemCopy(utf8_buffer_ + utf8_pos_, bytes, size);
    139     utf8_pos_ += size;
    140   }
    141 
    142   void AppendBytes(const char* bytes) {
    143     AppendBytes(bytes, StrLength(bytes));
    144   }
    145 
    146   void AppendByte(char c) {
    147     if (utf8_pos_ >= kUtf8BufferSize) return;
    148     utf8_buffer_[utf8_pos_++] = c;
    149   }
    150 
    151   void AppendInt(int n) {
    152     int space = kUtf8BufferSize - utf8_pos_;
    153     if (space <= 0) return;
    154     Vector<char> buffer(utf8_buffer_ + utf8_pos_, space);
    155     int size = SNPrintF(buffer, "%d", n);
    156     if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {
    157       utf8_pos_ += size;
    158     }
    159   }
    160 
    161   void AppendHex(uint32_t n) {
    162     int space = kUtf8BufferSize - utf8_pos_;
    163     if (space <= 0) return;
    164     Vector<char> buffer(utf8_buffer_ + utf8_pos_, space);
    165     int size = SNPrintF(buffer, "%x", n);
    166     if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {
    167       utf8_pos_ += size;
    168     }
    169   }
    170 
    171   const char* get() { return utf8_buffer_; }
    172   int size() const { return utf8_pos_; }
    173 
    174  private:
    175   static const int kUtf8BufferSize = 512;
    176   static const int kUtf16BufferSize = kUtf8BufferSize;
    177 
    178   int utf8_pos_;
    179   char utf8_buffer_[kUtf8BufferSize];
    180 };
    181 
    182 CodeEventLogger::CodeEventLogger(Isolate* isolate)
    183     : isolate_(isolate), name_buffer_(new NameBuffer) {}
    184 
    185 CodeEventLogger::~CodeEventLogger() { delete name_buffer_; }
    186 
    187 void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    188                                       AbstractCode* code, const char* comment) {
    189   name_buffer_->Init(tag);
    190   name_buffer_->AppendBytes(comment);
    191   LogRecordedBuffer(code, nullptr, name_buffer_->get(), name_buffer_->size());
    192 }
    193 
    194 void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    195                                       AbstractCode* code, Name* name) {
    196   name_buffer_->Init(tag);
    197   name_buffer_->AppendName(name);
    198   LogRecordedBuffer(code, nullptr, name_buffer_->get(), name_buffer_->size());
    199 }
    200 
    201 void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    202                                       AbstractCode* code,
    203                                       SharedFunctionInfo* shared, Name* name) {
    204   name_buffer_->Init(tag);
    205   name_buffer_->AppendBytes(ComputeMarker(shared, code));
    206   name_buffer_->AppendName(name);
    207   LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());
    208 }
    209 
    210 void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    211                                       AbstractCode* code,
    212                                       SharedFunctionInfo* shared, Name* source,
    213                                       int line, int column) {
    214   name_buffer_->Init(tag);
    215   name_buffer_->AppendBytes(ComputeMarker(shared, code));
    216   name_buffer_->AppendString(shared->DebugName());
    217   name_buffer_->AppendByte(' ');
    218   if (source->IsString()) {
    219     name_buffer_->AppendString(String::cast(source));
    220   } else {
    221     name_buffer_->AppendBytes("symbol(hash ");
    222     name_buffer_->AppendHex(Name::cast(source)->Hash());
    223     name_buffer_->AppendByte(')');
    224   }
    225   name_buffer_->AppendByte(':');
    226   name_buffer_->AppendInt(line);
    227   LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());
    228 }
    229 
    230 void CodeEventLogger::CodeCreateEvent(LogEventsAndTags tag,
    231                                       const wasm::WasmCode* code,
    232                                       wasm::WasmName name) {
    233   name_buffer_->Init(tag);
    234   if (name.is_empty()) {
    235     name_buffer_->AppendBytes("<wasm-unknown>");
    236   } else {
    237     name_buffer_->AppendBytes(name.start(), name.length());
    238   }
    239   name_buffer_->AppendByte('-');
    240   if (code->IsAnonymous()) {
    241     name_buffer_->AppendBytes("<anonymous>");
    242   } else {
    243     name_buffer_->AppendInt(code->index());
    244   }
    245   LogRecordedBuffer(code, name_buffer_->get(), name_buffer_->size());
    246 }
    247 
    248 void CodeEventLogger::RegExpCodeCreateEvent(AbstractCode* code,
    249                                             String* source) {
    250   name_buffer_->Init(CodeEventListener::REG_EXP_TAG);
    251   name_buffer_->AppendString(source);
    252   LogRecordedBuffer(code, nullptr, name_buffer_->get(), name_buffer_->size());
    253 }
    254 
    255 // Linux perf tool logging support
    256 class PerfBasicLogger : public CodeEventLogger {
    257  public:
    258   explicit PerfBasicLogger(Isolate* isolate);
    259   ~PerfBasicLogger() override;
    260 
    261   void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override {}
    262   void CodeDisableOptEvent(AbstractCode* code,
    263                            SharedFunctionInfo* shared) override {}
    264 
    265  private:
    266   void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
    267                          const char* name, int length) override;
    268   void LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
    269                          int length) override;
    270   void WriteLogRecordedBuffer(uintptr_t address, int size, const char* name,
    271                               int name_length);
    272 
    273   // Extension added to V8 log file name to get the low-level log name.
    274   static const char kFilenameFormatString[];
    275   static const int kFilenameBufferPadding;
    276 
    277   FILE* perf_output_handle_;
    278 };
    279 
    280 const char PerfBasicLogger::kFilenameFormatString[] = "/tmp/perf-%d.map";
    281 // Extra space for the PID in the filename
    282 const int PerfBasicLogger::kFilenameBufferPadding = 16;
    283 
    284 PerfBasicLogger::PerfBasicLogger(Isolate* isolate)
    285     : CodeEventLogger(isolate), perf_output_handle_(nullptr) {
    286   // Open the perf JIT dump file.
    287   int bufferSize = sizeof(kFilenameFormatString) + kFilenameBufferPadding;
    288   ScopedVector<char> perf_dump_name(bufferSize);
    289   int size = SNPrintF(
    290       perf_dump_name,
    291       kFilenameFormatString,
    292       base::OS::GetCurrentProcessId());
    293   CHECK_NE(size, -1);
    294   perf_output_handle_ =
    295       base::OS::FOpen(perf_dump_name.start(), base::OS::LogFileOpenMode);
    296   CHECK_NOT_NULL(perf_output_handle_);
    297   setvbuf(perf_output_handle_, nullptr, _IOLBF, 0);
    298 }
    299 
    300 
    301 PerfBasicLogger::~PerfBasicLogger() {
    302   fclose(perf_output_handle_);
    303   perf_output_handle_ = nullptr;
    304 }
    305 
    306 void PerfBasicLogger::WriteLogRecordedBuffer(uintptr_t address, int size,
    307                                              const char* name,
    308                                              int name_length) {
    309   // Linux perf expects hex literals without a leading 0x, while some
    310   // implementations of printf might prepend one when using the %p format
    311   // for pointers, leading to wrongly formatted JIT symbols maps.
    312   //
    313   // Instead, we use V8PRIxPTR format string and cast pointer to uintpr_t,
    314   // so that we have control over the exact output format.
    315   base::OS::FPrint(perf_output_handle_, "%" V8PRIxPTR " %x %.*s\n", address,
    316                    size, name_length, name);
    317 }
    318 
    319 void PerfBasicLogger::LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo*,
    320                                         const char* name, int length) {
    321   if (FLAG_perf_basic_prof_only_functions &&
    322       (code->kind() != AbstractCode::INTERPRETED_FUNCTION &&
    323        code->kind() != AbstractCode::BUILTIN &&
    324        code->kind() != AbstractCode::OPTIMIZED_FUNCTION)) {
    325     return;
    326   }
    327 
    328   WriteLogRecordedBuffer(static_cast<uintptr_t>(code->InstructionStart()),
    329                          code->InstructionSize(), name, length);
    330 }
    331 
    332 void PerfBasicLogger::LogRecordedBuffer(const wasm::WasmCode* code,
    333                                         const char* name, int length) {
    334   WriteLogRecordedBuffer(static_cast<uintptr_t>(code->instruction_start()),
    335                          code->instructions().length(), name, length);
    336 }
    337 
    338 // External CodeEventListener
    339 ExternalCodeEventListener::ExternalCodeEventListener(Isolate* isolate)
    340     : is_listening_(false), isolate_(isolate), code_event_handler_(nullptr) {}
    341 
    342 ExternalCodeEventListener::~ExternalCodeEventListener() {
    343   if (is_listening_) {
    344     StopListening();
    345   }
    346 }
    347 
    348 void ExternalCodeEventListener::LogExistingCode() {
    349   HandleScope scope(isolate_);
    350   ExistingCodeLogger logger(isolate_, this);
    351   logger.LogCodeObjects();
    352   logger.LogBytecodeHandlers();
    353   logger.LogCompiledFunctions();
    354 }
    355 
    356 void ExternalCodeEventListener::StartListening(
    357     CodeEventHandler* code_event_handler) {
    358   if (is_listening_ || code_event_handler == nullptr) {
    359     return;
    360   }
    361   code_event_handler_ = code_event_handler;
    362   is_listening_ = isolate_->code_event_dispatcher()->AddListener(this);
    363   if (is_listening_) {
    364     LogExistingCode();
    365   }
    366 }
    367 
    368 void ExternalCodeEventListener::StopListening() {
    369   if (!is_listening_) {
    370     return;
    371   }
    372 
    373   isolate_->code_event_dispatcher()->RemoveListener(this);
    374   is_listening_ = false;
    375 }
    376 
    377 void ExternalCodeEventListener::CodeCreateEvent(
    378     CodeEventListener::LogEventsAndTags tag, AbstractCode* code,
    379     const char* comment) {
    380   CodeEvent code_event;
    381   code_event.code_start_address =
    382       static_cast<uintptr_t>(code->InstructionStart());
    383   code_event.code_size = static_cast<size_t>(code->InstructionSize());
    384   code_event.function_name = isolate_->factory()->empty_string();
    385   code_event.script_name = isolate_->factory()->empty_string();
    386   code_event.script_line = 0;
    387   code_event.script_column = 0;
    388   code_event.code_type = GetCodeEventTypeForTag(tag);
    389   code_event.comment = comment;
    390 
    391   code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
    392 }
    393 
    394 void ExternalCodeEventListener::CodeCreateEvent(
    395     CodeEventListener::LogEventsAndTags tag, AbstractCode* code, Name* name) {
    396   Handle<String> name_string =
    397       Name::ToFunctionName(isolate_, Handle<Name>(name, isolate_))
    398           .ToHandleChecked();
    399 
    400   CodeEvent code_event;
    401   code_event.code_start_address =
    402       static_cast<uintptr_t>(code->InstructionStart());
    403   code_event.code_size = static_cast<size_t>(code->InstructionSize());
    404   code_event.function_name = name_string;
    405   code_event.script_name = isolate_->factory()->empty_string();
    406   code_event.script_line = 0;
    407   code_event.script_column = 0;
    408   code_event.code_type = GetCodeEventTypeForTag(tag);
    409   code_event.comment = "";
    410 
    411   code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
    412 }
    413 
    414 void ExternalCodeEventListener::CodeCreateEvent(
    415     CodeEventListener::LogEventsAndTags tag, AbstractCode* code,
    416     SharedFunctionInfo* shared, Name* name) {
    417   Handle<String> name_string =
    418       Name::ToFunctionName(isolate_, Handle<Name>(name, isolate_))
    419           .ToHandleChecked();
    420 
    421   CodeEvent code_event;
    422   code_event.code_start_address =
    423       static_cast<uintptr_t>(code->InstructionStart());
    424   code_event.code_size = static_cast<size_t>(code->InstructionSize());
    425   code_event.function_name = name_string;
    426   code_event.script_name = isolate_->factory()->empty_string();
    427   code_event.script_line = 0;
    428   code_event.script_column = 0;
    429   code_event.code_type = GetCodeEventTypeForTag(tag);
    430   code_event.comment = "";
    431 
    432   code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
    433 }
    434 
    435 void ExternalCodeEventListener::CodeCreateEvent(
    436     CodeEventListener::LogEventsAndTags tag, AbstractCode* code,
    437     SharedFunctionInfo* shared, Name* source, int line, int column) {
    438   Handle<String> name_string =
    439       Name::ToFunctionName(isolate_, Handle<Name>(shared->Name(), isolate_))
    440           .ToHandleChecked();
    441   Handle<String> source_string =
    442       Name::ToFunctionName(isolate_, Handle<Name>(source, isolate_))
    443           .ToHandleChecked();
    444 
    445   CodeEvent code_event;
    446   code_event.code_start_address =
    447       static_cast<uintptr_t>(code->InstructionStart());
    448   code_event.code_size = static_cast<size_t>(code->InstructionSize());
    449   code_event.function_name = name_string;
    450   code_event.script_name = source_string;
    451   code_event.script_line = line;
    452   code_event.script_column = column;
    453   code_event.code_type = GetCodeEventTypeForTag(tag);
    454   code_event.comment = "";
    455 
    456   code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
    457 }
    458 
    459 void ExternalCodeEventListener::CodeCreateEvent(LogEventsAndTags tag,
    460                                                 const wasm::WasmCode* code,
    461                                                 wasm::WasmName name) {
    462   // TODO(mmarchini): handle later
    463 }
    464 
    465 void ExternalCodeEventListener::RegExpCodeCreateEvent(AbstractCode* code,
    466                                                       String* source) {
    467   CodeEvent code_event;
    468   code_event.code_start_address =
    469       static_cast<uintptr_t>(code->InstructionStart());
    470   code_event.code_size = static_cast<size_t>(code->InstructionSize());
    471   code_event.function_name = Handle<String>(source, isolate_);
    472   code_event.script_name = isolate_->factory()->empty_string();
    473   code_event.script_line = 0;
    474   code_event.script_column = 0;
    475   code_event.code_type = GetCodeEventTypeForTag(CodeEventListener::REG_EXP_TAG);
    476   code_event.comment = "";
    477 
    478   code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
    479 }
    480 
    481 // Low-level logging support.
    482 class LowLevelLogger : public CodeEventLogger {
    483  public:
    484   LowLevelLogger(Isolate* isolate, const char* file_name);
    485   ~LowLevelLogger() override;
    486 
    487   void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override;
    488   void CodeDisableOptEvent(AbstractCode* code,
    489                            SharedFunctionInfo* shared) override {}
    490   void SnapshotPositionEvent(HeapObject* obj, int pos);
    491   void CodeMovingGCEvent() override;
    492 
    493  private:
    494   void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
    495                          const char* name, int length) override;
    496   void LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
    497                          int length) override;
    498 
    499   // Low-level profiling event structures.
    500   struct CodeCreateStruct {
    501     static const char kTag = 'C';
    502 
    503     int32_t name_size;
    504     Address code_address;
    505     int32_t code_size;
    506   };
    507 
    508 
    509   struct CodeMoveStruct {
    510     static const char kTag = 'M';
    511 
    512     Address from_address;
    513     Address to_address;
    514   };
    515 
    516 
    517   static const char kCodeMovingGCTag = 'G';
    518 
    519 
    520   // Extension added to V8 log file name to get the low-level log name.
    521   static const char kLogExt[];
    522 
    523   void LogCodeInfo();
    524   void LogWriteBytes(const char* bytes, int size);
    525 
    526   template <typename T>
    527   void LogWriteStruct(const T& s) {
    528     char tag = T::kTag;
    529     LogWriteBytes(reinterpret_cast<const char*>(&tag), sizeof(tag));
    530     LogWriteBytes(reinterpret_cast<const char*>(&s), sizeof(s));
    531   }
    532 
    533   FILE* ll_output_handle_;
    534 };
    535 
    536 const char LowLevelLogger::kLogExt[] = ".ll";
    537 
    538 LowLevelLogger::LowLevelLogger(Isolate* isolate, const char* name)
    539     : CodeEventLogger(isolate), ll_output_handle_(nullptr) {
    540   // Open the low-level log file.
    541   size_t len = strlen(name);
    542   ScopedVector<char> ll_name(static_cast<int>(len + sizeof(kLogExt)));
    543   MemCopy(ll_name.start(), name, len);
    544   MemCopy(ll_name.start() + len, kLogExt, sizeof(kLogExt));
    545   ll_output_handle_ =
    546       base::OS::FOpen(ll_name.start(), base::OS::LogFileOpenMode);
    547   setvbuf(ll_output_handle_, nullptr, _IOLBF, 0);
    548 
    549   LogCodeInfo();
    550 }
    551 
    552 
    553 LowLevelLogger::~LowLevelLogger() {
    554   fclose(ll_output_handle_);
    555   ll_output_handle_ = nullptr;
    556 }
    557 
    558 
    559 void LowLevelLogger::LogCodeInfo() {
    560 #if V8_TARGET_ARCH_IA32
    561   const char arch[] = "ia32";
    562 #elif V8_TARGET_ARCH_X64 && V8_TARGET_ARCH_64_BIT
    563   const char arch[] = "x64";
    564 #elif V8_TARGET_ARCH_X64 && V8_TARGET_ARCH_32_BIT
    565   const char arch[] = "x32";
    566 #elif V8_TARGET_ARCH_ARM
    567   const char arch[] = "arm";
    568 #elif V8_TARGET_ARCH_PPC
    569   const char arch[] = "ppc";
    570 #elif V8_TARGET_ARCH_MIPS
    571   const char arch[] = "mips";
    572 #elif V8_TARGET_ARCH_ARM64
    573   const char arch[] = "arm64";
    574 #elif V8_TARGET_ARCH_S390
    575   const char arch[] = "s390";
    576 #else
    577   const char arch[] = "unknown";
    578 #endif
    579   LogWriteBytes(arch, sizeof(arch));
    580 }
    581 
    582 void LowLevelLogger::LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo*,
    583                                        const char* name, int length) {
    584   CodeCreateStruct event;
    585   event.name_size = length;
    586   event.code_address = code->InstructionStart();
    587   event.code_size = code->InstructionSize();
    588   LogWriteStruct(event);
    589   LogWriteBytes(name, length);
    590   LogWriteBytes(reinterpret_cast<const char*>(code->InstructionStart()),
    591                 code->InstructionSize());
    592 }
    593 
    594 void LowLevelLogger::LogRecordedBuffer(const wasm::WasmCode* code,
    595                                        const char* name, int length) {
    596   CodeCreateStruct event;
    597   event.name_size = length;
    598   event.code_address = code->instruction_start();
    599   event.code_size = code->instructions().length();
    600   LogWriteStruct(event);
    601   LogWriteBytes(name, length);
    602   LogWriteBytes(reinterpret_cast<const char*>(code->instruction_start()),
    603                 code->instructions().length());
    604 }
    605 
    606 void LowLevelLogger::CodeMoveEvent(AbstractCode* from, AbstractCode* to) {
    607   CodeMoveStruct event;
    608   event.from_address = from->InstructionStart();
    609   event.to_address = to->InstructionStart();
    610   LogWriteStruct(event);
    611 }
    612 
    613 
    614 void LowLevelLogger::LogWriteBytes(const char* bytes, int size) {
    615   size_t rv = fwrite(bytes, 1, size, ll_output_handle_);
    616   DCHECK(static_cast<size_t>(size) == rv);
    617   USE(rv);
    618 }
    619 
    620 
    621 void LowLevelLogger::CodeMovingGCEvent() {
    622   const char tag = kCodeMovingGCTag;
    623 
    624   LogWriteBytes(&tag, sizeof(tag));
    625 }
    626 
    627 class JitLogger : public CodeEventLogger {
    628  public:
    629   JitLogger(Isolate* isolate, JitCodeEventHandler code_event_handler);
    630 
    631   void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override;
    632   void CodeDisableOptEvent(AbstractCode* code,
    633                            SharedFunctionInfo* shared) override {}
    634   void AddCodeLinePosInfoEvent(void* jit_handler_data, int pc_offset,
    635                                int position,
    636                                JitCodeEvent::PositionType position_type);
    637 
    638   void* StartCodePosInfoEvent();
    639   void EndCodePosInfoEvent(Address start_address, void* jit_handler_data);
    640 
    641  private:
    642   void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
    643                          const char* name, int length) override;
    644   void LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
    645                          int length) override;
    646 
    647   JitCodeEventHandler code_event_handler_;
    648   base::Mutex logger_mutex_;
    649 };
    650 
    651 JitLogger::JitLogger(Isolate* isolate, JitCodeEventHandler code_event_handler)
    652     : CodeEventLogger(isolate), code_event_handler_(code_event_handler) {}
    653 
    654 void JitLogger::LogRecordedBuffer(AbstractCode* code,
    655                                   SharedFunctionInfo* shared, const char* name,
    656                                   int length) {
    657   JitCodeEvent event;
    658   memset(&event, 0, sizeof(event));
    659   event.type = JitCodeEvent::CODE_ADDED;
    660   event.code_start = reinterpret_cast<void*>(code->InstructionStart());
    661   event.code_type =
    662       code->IsCode() ? JitCodeEvent::JIT_CODE : JitCodeEvent::BYTE_CODE;
    663   event.code_len = code->InstructionSize();
    664   Handle<SharedFunctionInfo> shared_function_handle;
    665   if (shared && shared->script()->IsScript()) {
    666     shared_function_handle =
    667         Handle<SharedFunctionInfo>(shared, shared->GetIsolate());
    668   }
    669   event.script = ToApiHandle<v8::UnboundScript>(shared_function_handle);
    670   event.name.str = name;
    671   event.name.len = length;
    672   event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
    673   code_event_handler_(&event);
    674 }
    675 
    676 void JitLogger::LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
    677                                   int length) {
    678   JitCodeEvent event;
    679   memset(&event, 0, sizeof(event));
    680   event.type = JitCodeEvent::CODE_ADDED;
    681   event.code_type = JitCodeEvent::JIT_CODE;
    682   event.code_start = code->instructions().start();
    683   event.code_len = code->instructions().length();
    684   event.name.str = name;
    685   event.name.len = length;
    686   event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
    687   code_event_handler_(&event);
    688 }
    689 
    690 void JitLogger::CodeMoveEvent(AbstractCode* from, AbstractCode* to) {
    691   base::LockGuard<base::Mutex> guard(&logger_mutex_);
    692 
    693   JitCodeEvent event;
    694   event.type = JitCodeEvent::CODE_MOVED;
    695   event.code_type =
    696       from->IsCode() ? JitCodeEvent::JIT_CODE : JitCodeEvent::BYTE_CODE;
    697   event.code_start = reinterpret_cast<void*>(from->InstructionStart());
    698   event.code_len = from->InstructionSize();
    699   event.new_code_start = reinterpret_cast<void*>(to->InstructionStart());
    700   event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
    701 
    702   code_event_handler_(&event);
    703 }
    704 
    705 void JitLogger::AddCodeLinePosInfoEvent(
    706     void* jit_handler_data,
    707     int pc_offset,
    708     int position,
    709     JitCodeEvent::PositionType position_type) {
    710   JitCodeEvent event;
    711   memset(&event, 0, sizeof(event));
    712   event.type = JitCodeEvent::CODE_ADD_LINE_POS_INFO;
    713   event.user_data = jit_handler_data;
    714   event.line_info.offset = pc_offset;
    715   event.line_info.pos = position;
    716   event.line_info.position_type = position_type;
    717   event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
    718 
    719   code_event_handler_(&event);
    720 }
    721 
    722 
    723 void* JitLogger::StartCodePosInfoEvent() {
    724   JitCodeEvent event;
    725   memset(&event, 0, sizeof(event));
    726   event.type = JitCodeEvent::CODE_START_LINE_INFO_RECORDING;
    727   event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
    728 
    729   code_event_handler_(&event);
    730   return event.user_data;
    731 }
    732 
    733 void JitLogger::EndCodePosInfoEvent(Address start_address,
    734                                     void* jit_handler_data) {
    735   JitCodeEvent event;
    736   memset(&event, 0, sizeof(event));
    737   event.type = JitCodeEvent::CODE_END_LINE_INFO_RECORDING;
    738   event.code_start = reinterpret_cast<void*>(start_address);
    739   event.user_data = jit_handler_data;
    740   event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
    741 
    742   code_event_handler_(&event);
    743 }
    744 
    745 
    746 // TODO(lpy): Keeping sampling thread inside V8 is a workaround currently,
    747 // the reason is to reduce code duplication during migration to sampler library,
    748 // sampling thread, as well as the sampler, will be moved to D8 eventually.
    749 class SamplingThread : public base::Thread {
    750  public:
    751   static const int kSamplingThreadStackSize = 64 * KB;
    752 
    753   SamplingThread(sampler::Sampler* sampler, int interval_microseconds)
    754       : base::Thread(
    755             base::Thread::Options("SamplingThread", kSamplingThreadStackSize)),
    756         sampler_(sampler),
    757         interval_microseconds_(interval_microseconds) {}
    758   void Run() override {
    759     while (sampler_->IsProfiling()) {
    760       sampler_->DoSample();
    761       base::OS::Sleep(
    762           base::TimeDelta::FromMicroseconds(interval_microseconds_));
    763     }
    764   }
    765 
    766  private:
    767   sampler::Sampler* sampler_;
    768   const int interval_microseconds_;
    769 };
    770 
    771 
    772 // The Profiler samples pc and sp values for the main thread.
    773 // Each sample is appended to a circular buffer.
    774 // An independent thread removes data and writes it to the log.
    775 // This design minimizes the time spent in the sampler.
    776 //
    777 class Profiler: public base::Thread {
    778  public:
    779   explicit Profiler(Isolate* isolate);
    780   void Engage();
    781   void Disengage();
    782 
    783   // Inserts collected profiling data into buffer.
    784   void Insert(v8::TickSample* sample) {
    785     if (paused_)
    786       return;
    787 
    788     if (Succ(head_) == static_cast<int>(base::Relaxed_Load(&tail_))) {
    789       overflow_ = true;
    790     } else {
    791       buffer_[head_] = *sample;
    792       head_ = Succ(head_);
    793       buffer_semaphore_.Signal();  // Tell we have an element.
    794     }
    795   }
    796 
    797   virtual void Run();
    798 
    799   // Pause and Resume TickSample data collection.
    800   void Pause() { paused_ = true; }
    801   void Resume() { paused_ = false; }
    802 
    803  private:
    804   // Waits for a signal and removes profiling data.
    805   bool Remove(v8::TickSample* sample) {
    806     buffer_semaphore_.Wait();  // Wait for an element.
    807     *sample = buffer_[base::Relaxed_Load(&tail_)];
    808     bool result = overflow_;
    809     base::Relaxed_Store(
    810         &tail_, static_cast<base::Atomic32>(Succ(base::Relaxed_Load(&tail_))));
    811     overflow_ = false;
    812     return result;
    813   }
    814 
    815   // Returns the next index in the cyclic buffer.
    816   int Succ(int index) { return (index + 1) % kBufferSize; }
    817 
    818   Isolate* isolate_;
    819   // Cyclic buffer for communicating profiling samples
    820   // between the signal handler and the worker thread.
    821   static const int kBufferSize = 128;
    822   v8::TickSample buffer_[kBufferSize];  // Buffer storage.
    823   int head_;  // Index to the buffer head.
    824   base::Atomic32 tail_;             // Index to the buffer tail.
    825   bool overflow_;  // Tell whether a buffer overflow has occurred.
    826   // Semaphore used for buffer synchronization.
    827   base::Semaphore buffer_semaphore_;
    828 
    829   // Tells whether profiler is engaged, that is, processing thread is stated.
    830   bool engaged_;
    831 
    832   // Tells whether worker thread should continue running.
    833   base::Atomic32 running_;
    834 
    835   // Tells whether we are currently recording tick samples.
    836   bool paused_;
    837 };
    838 
    839 
    840 //
    841 // Ticker used to provide ticks to the profiler and the sliding state
    842 // window.
    843 //
    844 class Ticker: public sampler::Sampler {
    845  public:
    846   Ticker(Isolate* isolate, int interval_microseconds)
    847       : sampler::Sampler(reinterpret_cast<v8::Isolate*>(isolate)),
    848         profiler_(nullptr),
    849         sampling_thread_(new SamplingThread(this, interval_microseconds)) {}
    850 
    851   ~Ticker() {
    852     if (IsActive()) Stop();
    853     delete sampling_thread_;
    854   }
    855 
    856   void SetProfiler(Profiler* profiler) {
    857     DCHECK_NULL(profiler_);
    858     profiler_ = profiler;
    859     IncreaseProfilingDepth();
    860     if (!IsActive()) Start();
    861     sampling_thread_->StartSynchronously();
    862   }
    863 
    864   void ClearProfiler() {
    865     profiler_ = nullptr;
    866     if (IsActive()) Stop();
    867     DecreaseProfilingDepth();
    868     sampling_thread_->Join();
    869   }
    870 
    871   void SampleStack(const v8::RegisterState& state) override {
    872     if (!profiler_) return;
    873     Isolate* isolate = reinterpret_cast<Isolate*>(this->isolate());
    874     TickSample sample;
    875     sample.Init(isolate, state, TickSample::kIncludeCEntryFrame, true);
    876     profiler_->Insert(&sample);
    877   }
    878 
    879  private:
    880   Profiler* profiler_;
    881   SamplingThread* sampling_thread_;
    882 };
    883 
    884 //
    885 // Profiler implementation when invoking with --prof.
    886 //
    887 Profiler::Profiler(Isolate* isolate)
    888     : base::Thread(Options("v8:Profiler")),
    889       isolate_(isolate),
    890       head_(0),
    891       overflow_(false),
    892       buffer_semaphore_(0),
    893       engaged_(false),
    894       paused_(false) {
    895   base::Relaxed_Store(&tail_, 0);
    896   base::Relaxed_Store(&running_, 0);
    897 }
    898 
    899 
    900 void Profiler::Engage() {
    901   if (engaged_) return;
    902   engaged_ = true;
    903 
    904   std::vector<base::OS::SharedLibraryAddress> addresses =
    905       base::OS::GetSharedLibraryAddresses();
    906   for (const auto& address : addresses) {
    907     LOG(isolate_, SharedLibraryEvent(address.library_path, address.start,
    908                                      address.end, address.aslr_slide));
    909   }
    910 
    911   // Start thread processing the profiler buffer.
    912   base::Relaxed_Store(&running_, 1);
    913   Start();
    914 
    915   // Register to get ticks.
    916   Logger* logger = isolate_->logger();
    917   logger->ticker_->SetProfiler(this);
    918 
    919   logger->ProfilerBeginEvent();
    920 }
    921 
    922 
    923 void Profiler::Disengage() {
    924   if (!engaged_) return;
    925 
    926   // Stop receiving ticks.
    927   isolate_->logger()->ticker_->ClearProfiler();
    928 
    929   // Terminate the worker thread by setting running_ to false,
    930   // inserting a fake element in the queue and then wait for
    931   // the thread to terminate.
    932   base::Relaxed_Store(&running_, 0);
    933   v8::TickSample sample;
    934   // Reset 'paused_' flag, otherwise semaphore may not be signalled.
    935   Resume();
    936   Insert(&sample);
    937   Join();
    938 
    939   LOG(isolate_, UncheckedStringEvent("profiler", "end"));
    940 }
    941 
    942 
    943 void Profiler::Run() {
    944   v8::TickSample sample;
    945   bool overflow = Remove(&sample);
    946   while (base::Relaxed_Load(&running_)) {
    947     LOG(isolate_, TickEvent(&sample, overflow));
    948     overflow = Remove(&sample);
    949   }
    950 }
    951 
    952 
    953 //
    954 // Logger class implementation.
    955 //
    956 
    957 Logger::Logger(Isolate* isolate)
    958     : isolate_(isolate),
    959       ticker_(nullptr),
    960       profiler_(nullptr),
    961       log_events_(nullptr),
    962       is_logging_(false),
    963       log_(nullptr),
    964       perf_basic_logger_(nullptr),
    965       perf_jit_logger_(nullptr),
    966       ll_logger_(nullptr),
    967       jit_logger_(nullptr),
    968       is_initialized_(false),
    969       existing_code_logger_(isolate) {}
    970 
    971 Logger::~Logger() {
    972   delete log_;
    973 }
    974 
    975 void Logger::AddCodeEventListener(CodeEventListener* listener) {
    976   bool result = isolate_->code_event_dispatcher()->AddListener(listener);
    977   CHECK(result);
    978 }
    979 
    980 void Logger::RemoveCodeEventListener(CodeEventListener* listener) {
    981   isolate_->code_event_dispatcher()->RemoveListener(listener);
    982 }
    983 
    984 void Logger::ProfilerBeginEvent() {
    985   if (!log_->IsEnabled()) return;
    986   Log::MessageBuilder msg(log_);
    987   msg << "profiler" << kNext << "begin" << kNext << FLAG_prof_sampling_interval;
    988   msg.WriteToLogFile();
    989 }
    990 
    991 
    992 void Logger::StringEvent(const char* name, const char* value) {
    993   if (FLAG_log) UncheckedStringEvent(name, value);
    994 }
    995 
    996 
    997 void Logger::UncheckedStringEvent(const char* name, const char* value) {
    998   if (!log_->IsEnabled()) return;
    999   Log::MessageBuilder msg(log_);
   1000   msg << name << kNext << value;
   1001   msg.WriteToLogFile();
   1002 }
   1003 
   1004 
   1005 void Logger::IntPtrTEvent(const char* name, intptr_t value) {
   1006   if (FLAG_log) UncheckedIntPtrTEvent(name, value);
   1007 }
   1008 
   1009 
   1010 void Logger::UncheckedIntPtrTEvent(const char* name, intptr_t value) {
   1011   if (!log_->IsEnabled()) return;
   1012   Log::MessageBuilder msg(log_);
   1013   msg << name << kNext;
   1014   msg.AppendFormatString("%" V8PRIdPTR, value);
   1015   msg.WriteToLogFile();
   1016 }
   1017 
   1018 
   1019 void Logger::HandleEvent(const char* name, Object** location) {
   1020   if (!log_->IsEnabled() || !FLAG_log_handles) return;
   1021   Log::MessageBuilder msg(log_);
   1022   msg << name << kNext << static_cast<void*>(location);
   1023   msg.WriteToLogFile();
   1024 }
   1025 
   1026 
   1027 void Logger::ApiSecurityCheck() {
   1028   if (!log_->IsEnabled() || !FLAG_log_api) return;
   1029   Log::MessageBuilder msg(log_);
   1030   msg << "api" << kNext << "check-security";
   1031   msg.WriteToLogFile();
   1032 }
   1033 
   1034 void Logger::SharedLibraryEvent(const std::string& library_path,
   1035                                 uintptr_t start, uintptr_t end,
   1036                                 intptr_t aslr_slide) {
   1037   if (!log_->IsEnabled() || !FLAG_prof_cpp) return;
   1038   Log::MessageBuilder msg(log_);
   1039   msg << "shared-library" << kNext << library_path.c_str() << kNext
   1040       << reinterpret_cast<void*>(start) << kNext << reinterpret_cast<void*>(end)
   1041       << kNext << aslr_slide;
   1042   msg.WriteToLogFile();
   1043 }
   1044 
   1045 void Logger::CodeDeoptEvent(Code* code, DeoptimizeKind kind, Address pc,
   1046                             int fp_to_sp_delta) {
   1047   if (!log_->IsEnabled()) return;
   1048   Deoptimizer::DeoptInfo info = Deoptimizer::GetDeoptInfo(code, pc);
   1049   Log::MessageBuilder msg(log_);
   1050   msg << "code-deopt" << kNext << timer_.Elapsed().InMicroseconds() << kNext
   1051       << code->CodeSize() << kNext
   1052       << reinterpret_cast<void*>(code->InstructionStart());
   1053 
   1054   // Deoptimization position.
   1055   std::ostringstream deopt_location;
   1056   int inlining_id = -1;
   1057   int script_offset = -1;
   1058   if (info.position.IsKnown()) {
   1059     info.position.Print(deopt_location, code);
   1060     inlining_id = info.position.InliningId();
   1061     script_offset = info.position.ScriptOffset();
   1062   } else {
   1063     deopt_location << "<unknown>";
   1064   }
   1065   msg << kNext << inlining_id << kNext << script_offset << kNext;
   1066   msg << Deoptimizer::MessageFor(kind) << kNext;
   1067   msg << deopt_location.str().c_str() << kNext
   1068       << DeoptimizeReasonToString(info.deopt_reason);
   1069   msg.WriteToLogFile();
   1070 }
   1071 
   1072 
   1073 void Logger::CurrentTimeEvent() {
   1074   if (!log_->IsEnabled()) return;
   1075   DCHECK(FLAG_log_internal_timer_events);
   1076   Log::MessageBuilder msg(log_);
   1077   msg << "current-time" << kNext << timer_.Elapsed().InMicroseconds();
   1078   msg.WriteToLogFile();
   1079 }
   1080 
   1081 
   1082 void Logger::TimerEvent(Logger::StartEnd se, const char* name) {
   1083   if (!log_->IsEnabled()) return;
   1084   Log::MessageBuilder msg(log_);
   1085   switch (se) {
   1086     case START:
   1087       msg << "timer-event-start";
   1088       break;
   1089     case END:
   1090       msg << "timer-event-end";
   1091       break;
   1092     case STAMP:
   1093       msg << "timer-event";
   1094   }
   1095   msg << kNext << name << kNext << timer_.Elapsed().InMicroseconds();
   1096   msg.WriteToLogFile();
   1097 }
   1098 
   1099 // static
   1100 void Logger::EnterExternal(Isolate* isolate) {
   1101   DCHECK(FLAG_log_internal_timer_events);
   1102   LOG(isolate, TimerEvent(START, TimerEventExternal::name()));
   1103   DCHECK(isolate->current_vm_state() == JS);
   1104   isolate->set_current_vm_state(EXTERNAL);
   1105 }
   1106 
   1107 // static
   1108 void Logger::LeaveExternal(Isolate* isolate) {
   1109   DCHECK(FLAG_log_internal_timer_events);
   1110   LOG(isolate, TimerEvent(END, TimerEventExternal::name()));
   1111   DCHECK(isolate->current_vm_state() == EXTERNAL);
   1112   isolate->set_current_vm_state(JS);
   1113 }
   1114 
   1115 // Instantiate template methods.
   1116 #define V(TimerName, expose)                                           \
   1117   template void TimerEventScope<TimerEvent##TimerName>::LogTimerEvent( \
   1118       Logger::StartEnd se);
   1119 TIMER_EVENTS_LIST(V)
   1120 #undef V
   1121 
   1122 void Logger::ApiNamedPropertyAccess(const char* tag, JSObject* holder,
   1123                                     Object* property_name) {
   1124   DCHECK(property_name->IsName());
   1125   if (!log_->IsEnabled() || !FLAG_log_api) return;
   1126   Log::MessageBuilder msg(log_);
   1127   msg << "api" << kNext << tag << kNext << holder->class_name() << kNext
   1128       << Name::cast(property_name);
   1129   msg.WriteToLogFile();
   1130 }
   1131 
   1132 void Logger::ApiIndexedPropertyAccess(const char* tag,
   1133                                       JSObject* holder,
   1134                                       uint32_t index) {
   1135   if (!log_->IsEnabled() || !FLAG_log_api) return;
   1136   Log::MessageBuilder msg(log_);
   1137   msg << "api" << kNext << tag << kNext << holder->class_name() << kNext
   1138       << index;
   1139   msg.WriteToLogFile();
   1140 }
   1141 
   1142 
   1143 void Logger::ApiObjectAccess(const char* tag, JSObject* object) {
   1144   if (!log_->IsEnabled() || !FLAG_log_api) return;
   1145   Log::MessageBuilder msg(log_);
   1146   msg << "api" << kNext << tag << kNext << object->class_name();
   1147   msg.WriteToLogFile();
   1148 }
   1149 
   1150 
   1151 void Logger::ApiEntryCall(const char* name) {
   1152   if (!log_->IsEnabled() || !FLAG_log_api) return;
   1153   Log::MessageBuilder msg(log_);
   1154   msg << "api" << kNext << name;
   1155   msg.WriteToLogFile();
   1156 }
   1157 
   1158 
   1159 void Logger::NewEvent(const char* name, void* object, size_t size) {
   1160   if (!log_->IsEnabled() || !FLAG_log) return;
   1161   Log::MessageBuilder msg(log_);
   1162   msg << "new" << kNext << name << kNext << object << kNext
   1163       << static_cast<unsigned int>(size);
   1164   msg.WriteToLogFile();
   1165 }
   1166 
   1167 
   1168 void Logger::DeleteEvent(const char* name, void* object) {
   1169   if (!log_->IsEnabled() || !FLAG_log) return;
   1170   Log::MessageBuilder msg(log_);
   1171   msg << "delete" << kNext << name << kNext << object;
   1172   msg.WriteToLogFile();
   1173 }
   1174 
   1175 
   1176 void Logger::CallbackEventInternal(const char* prefix, Name* name,
   1177                                    Address entry_point) {
   1178   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1179   Log::MessageBuilder msg(log_);
   1180   msg << kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT] << kNext
   1181       << kLogEventsNames[CodeEventListener::CALLBACK_TAG] << kNext << -2
   1182       << kNext << timer_.Elapsed().InMicroseconds() << kNext
   1183       << reinterpret_cast<void*>(entry_point) << kNext << 1 << kNext << prefix
   1184       << name;
   1185   msg.WriteToLogFile();
   1186 }
   1187 
   1188 
   1189 void Logger::CallbackEvent(Name* name, Address entry_point) {
   1190   CallbackEventInternal("", name, entry_point);
   1191 }
   1192 
   1193 
   1194 void Logger::GetterCallbackEvent(Name* name, Address entry_point) {
   1195   CallbackEventInternal("get ", name, entry_point);
   1196 }
   1197 
   1198 
   1199 void Logger::SetterCallbackEvent(Name* name, Address entry_point) {
   1200   CallbackEventInternal("set ", name, entry_point);
   1201 }
   1202 
   1203 namespace {
   1204 
   1205 void AppendCodeCreateHeader(Log::MessageBuilder& msg,
   1206                             CodeEventListener::LogEventsAndTags tag,
   1207                             AbstractCode::Kind kind, uint8_t* address, int size,
   1208                             base::ElapsedTimer* timer) {
   1209   msg << kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT]
   1210       << Logger::kNext << kLogEventsNames[tag] << Logger::kNext << kind
   1211       << Logger::kNext << timer->Elapsed().InMicroseconds() << Logger::kNext
   1212       << reinterpret_cast<void*>(address) << Logger::kNext << size
   1213       << Logger::kNext;
   1214 }
   1215 
   1216 void AppendCodeCreateHeader(Log::MessageBuilder& msg,
   1217                             CodeEventListener::LogEventsAndTags tag,
   1218                             AbstractCode* code, base::ElapsedTimer* timer) {
   1219   AppendCodeCreateHeader(msg, tag, code->kind(),
   1220                          reinterpret_cast<uint8_t*>(code->InstructionStart()),
   1221                          code->InstructionSize(), timer);
   1222 }
   1223 
   1224 }  // namespace
   1225 
   1226 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
   1227                              AbstractCode* code, const char* comment) {
   1228   if (!is_listening_to_code_events()) return;
   1229   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1230   Log::MessageBuilder msg(log_);
   1231   AppendCodeCreateHeader(msg, tag, code, &timer_);
   1232   msg << comment;
   1233   msg.WriteToLogFile();
   1234 }
   1235 
   1236 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
   1237                              AbstractCode* code, Name* name) {
   1238   if (!is_listening_to_code_events()) return;
   1239   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1240   Log::MessageBuilder msg(log_);
   1241   AppendCodeCreateHeader(msg, tag, code, &timer_);
   1242   msg << name;
   1243   msg.WriteToLogFile();
   1244 }
   1245 
   1246 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
   1247                              AbstractCode* code, SharedFunctionInfo* shared,
   1248                              Name* name) {
   1249   if (!is_listening_to_code_events()) return;
   1250   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1251   if (code == AbstractCode::cast(
   1252                   isolate_->builtins()->builtin(Builtins::kCompileLazy))) {
   1253     return;
   1254   }
   1255 
   1256   Log::MessageBuilder msg(log_);
   1257   AppendCodeCreateHeader(msg, tag, code, &timer_);
   1258   msg << name << kNext << reinterpret_cast<void*>(shared->address()) << kNext
   1259       << ComputeMarker(shared, code);
   1260   msg.WriteToLogFile();
   1261 }
   1262 
   1263 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
   1264                              const wasm::WasmCode* code, wasm::WasmName name) {
   1265   if (!is_listening_to_code_events()) return;
   1266   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1267   Log::MessageBuilder msg(log_);
   1268   AppendCodeCreateHeader(msg, tag, AbstractCode::Kind::WASM_FUNCTION,
   1269                          code->instructions().start(),
   1270                          code->instructions().length(), &timer_);
   1271   if (name.is_empty()) {
   1272     msg << "<unknown wasm>";
   1273   } else {
   1274     msg.AppendString(name);
   1275   }
   1276   // We have to add two extra fields that allow the tick processor to group
   1277   // events for the same wasm function, even if it gets compiled again. For
   1278   // normal JS functions, we use the shared function info. For wasm, the pointer
   1279   // to the native module + function index works well enough.
   1280   // TODO(herhut) Clean up the tick processor code instead.
   1281   void* tag_ptr =
   1282       reinterpret_cast<byte*>(code->native_module()) + code->index();
   1283   msg << kNext << tag_ptr << kNext << ComputeMarker(code);
   1284   msg.WriteToLogFile();
   1285 }
   1286 
   1287 // Although, it is possible to extract source and line from
   1288 // the SharedFunctionInfo object, we left it to caller
   1289 // to leave logging functions free from heap allocations.
   1290 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
   1291                              AbstractCode* code, SharedFunctionInfo* shared,
   1292                              Name* source, int line, int column) {
   1293   if (!is_listening_to_code_events()) return;
   1294   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1295   {
   1296     Log::MessageBuilder msg(log_);
   1297     AppendCodeCreateHeader(msg, tag, code, &timer_);
   1298     msg << shared->DebugName() << " " << source << ":" << line << ":" << column
   1299         << kNext << reinterpret_cast<void*>(shared->address()) << kNext
   1300         << ComputeMarker(shared, code);
   1301     msg.WriteToLogFile();
   1302   }
   1303 
   1304   if (!FLAG_log_source_code) return;
   1305   Object* script_object = shared->script();
   1306   if (!script_object->IsScript()) return;
   1307   Script* script = Script::cast(script_object);
   1308   if (!EnsureLogScriptSource(script)) return;
   1309 
   1310   // We log source code information in the form:
   1311   //
   1312   // code-source-info <addr>,<script>,<start>,<end>,<pos>,<inline-pos>,<fns>
   1313   //
   1314   // where
   1315   //   <addr> is code object address
   1316   //   <script> is script id
   1317   //   <start> is the starting position inside the script
   1318   //   <end> is the end position inside the script
   1319   //   <pos> is source position table encoded in the string,
   1320   //      it is a sequence of C<code-offset>O<script-offset>[I<inlining-id>]
   1321   //      where
   1322   //        <code-offset> is the offset within the code object
   1323   //        <script-offset> is the position within the script
   1324   //        <inlining-id> is the offset in the <inlining> table
   1325   //   <inlining> table is a sequence of strings of the form
   1326   //      F<function-id>O<script-offset>[I<inlining-id>
   1327   //      where
   1328   //         <function-id> is an index into the <fns> function table
   1329   //   <fns> is the function table encoded as a sequence of strings
   1330   //      S<shared-function-info-address>
   1331   Log::MessageBuilder msg(log_);
   1332   msg << "code-source-info" << kNext
   1333       << reinterpret_cast<void*>(code->InstructionStart()) << kNext
   1334       << script->id() << kNext << shared->StartPosition() << kNext
   1335       << shared->EndPosition() << kNext;
   1336 
   1337   SourcePositionTableIterator iterator(code->source_position_table());
   1338   bool is_first = true;
   1339   bool hasInlined = false;
   1340   for (; !iterator.done(); iterator.Advance()) {
   1341     if (is_first) {
   1342       is_first = false;
   1343     }
   1344     SourcePosition pos = iterator.source_position();
   1345     msg << "C" << iterator.code_offset() << "O" << pos.ScriptOffset();
   1346     if (pos.isInlined()) {
   1347       msg << "I" << pos.InliningId();
   1348       hasInlined = true;
   1349     }
   1350   }
   1351   msg << kNext;
   1352   int maxInlinedId = -1;
   1353   if (hasInlined) {
   1354     PodArray<InliningPosition>* inlining_positions =
   1355         DeoptimizationData::cast(Code::cast(code)->deoptimization_data())
   1356             ->InliningPositions();
   1357     for (int i = 0; i < inlining_positions->length(); i++) {
   1358       InliningPosition inlining_pos = inlining_positions->get(i);
   1359       msg << "F";
   1360       if (inlining_pos.inlined_function_id != -1) {
   1361         msg << inlining_pos.inlined_function_id;
   1362         if (inlining_pos.inlined_function_id > maxInlinedId) {
   1363           maxInlinedId = inlining_pos.inlined_function_id;
   1364         }
   1365       }
   1366       SourcePosition pos = inlining_pos.position;
   1367       msg << "O" << pos.ScriptOffset();
   1368       if (pos.isInlined()) {
   1369         msg << "I" << pos.InliningId();
   1370       }
   1371     }
   1372   }
   1373   msg << kNext;
   1374   if (hasInlined) {
   1375     DeoptimizationData* deopt_data =
   1376         DeoptimizationData::cast(Code::cast(code)->deoptimization_data());
   1377 
   1378     msg << std::hex;
   1379     for (int i = 0; i <= maxInlinedId; i++) {
   1380       msg << "S"
   1381           << reinterpret_cast<void*>(
   1382                  deopt_data->GetInlinedFunction(i)->address());
   1383     }
   1384     msg << std::dec;
   1385   }
   1386   msg.WriteToLogFile();
   1387 }
   1388 
   1389 void Logger::CodeDisableOptEvent(AbstractCode* code,
   1390                                  SharedFunctionInfo* shared) {
   1391   if (!is_listening_to_code_events()) return;
   1392   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1393   Log::MessageBuilder msg(log_);
   1394   msg << kLogEventsNames[CodeEventListener::CODE_DISABLE_OPT_EVENT] << kNext
   1395       << shared->DebugName() << kNext
   1396       << GetBailoutReason(shared->disable_optimization_reason());
   1397   msg.WriteToLogFile();
   1398 }
   1399 
   1400 
   1401 void Logger::CodeMovingGCEvent() {
   1402   if (!is_listening_to_code_events()) return;
   1403   if (!log_->IsEnabled() || !FLAG_ll_prof) return;
   1404   base::OS::SignalCodeMovingGC();
   1405 }
   1406 
   1407 void Logger::RegExpCodeCreateEvent(AbstractCode* code, String* source) {
   1408   if (!is_listening_to_code_events()) return;
   1409   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1410   Log::MessageBuilder msg(log_);
   1411   AppendCodeCreateHeader(msg, CodeEventListener::REG_EXP_TAG, code, &timer_);
   1412   msg << source;
   1413   msg.WriteToLogFile();
   1414 }
   1415 
   1416 void Logger::CodeMoveEvent(AbstractCode* from, AbstractCode* to) {
   1417   if (!is_listening_to_code_events()) return;
   1418   MoveEventInternal(CodeEventListener::CODE_MOVE_EVENT, from->address(),
   1419                     to->address());
   1420 }
   1421 
   1422 namespace {
   1423 
   1424 void CodeLinePosEvent(JitLogger* jit_logger, Address code_start,
   1425                       SourcePositionTableIterator& iter) {
   1426   if (jit_logger) {
   1427     void* jit_handler_data = jit_logger->StartCodePosInfoEvent();
   1428     for (; !iter.done(); iter.Advance()) {
   1429       if (iter.is_statement()) {
   1430         jit_logger->AddCodeLinePosInfoEvent(
   1431             jit_handler_data, iter.code_offset(),
   1432             iter.source_position().ScriptOffset(),
   1433             JitCodeEvent::STATEMENT_POSITION);
   1434       }
   1435       jit_logger->AddCodeLinePosInfoEvent(jit_handler_data, iter.code_offset(),
   1436                                           iter.source_position().ScriptOffset(),
   1437                                           JitCodeEvent::POSITION);
   1438     }
   1439     jit_logger->EndCodePosInfoEvent(code_start, jit_handler_data);
   1440   }
   1441 }
   1442 
   1443 }  // namespace
   1444 
   1445 void Logger::CodeLinePosInfoRecordEvent(Address code_start,
   1446                                         ByteArray* source_position_table) {
   1447   SourcePositionTableIterator iter(source_position_table);
   1448   CodeLinePosEvent(jit_logger_, code_start, iter);
   1449 }
   1450 
   1451 void Logger::CodeLinePosInfoRecordEvent(
   1452     Address code_start, Vector<const byte> source_position_table) {
   1453   SourcePositionTableIterator iter(source_position_table);
   1454   CodeLinePosEvent(jit_logger_, code_start, iter);
   1455 }
   1456 
   1457 void Logger::CodeNameEvent(Address addr, int pos, const char* code_name) {
   1458   if (code_name == nullptr) return;  // Not a code object.
   1459   Log::MessageBuilder msg(log_);
   1460   msg << kLogEventsNames[CodeEventListener::SNAPSHOT_CODE_NAME_EVENT] << kNext
   1461       << pos << kNext << code_name;
   1462   msg.WriteToLogFile();
   1463 }
   1464 
   1465 
   1466 void Logger::SharedFunctionInfoMoveEvent(Address from, Address to) {
   1467   if (!is_listening_to_code_events()) return;
   1468   MoveEventInternal(CodeEventListener::SHARED_FUNC_MOVE_EVENT, from, to);
   1469 }
   1470 
   1471 void Logger::MoveEventInternal(CodeEventListener::LogEventsAndTags event,
   1472                                Address from, Address to) {
   1473   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1474   Log::MessageBuilder msg(log_);
   1475   msg << kLogEventsNames[event] << kNext << reinterpret_cast<void*>(from)
   1476       << kNext << reinterpret_cast<void*>(to);
   1477   msg.WriteToLogFile();
   1478 }
   1479 
   1480 
   1481 void Logger::ResourceEvent(const char* name, const char* tag) {
   1482   if (!log_->IsEnabled() || !FLAG_log) return;
   1483   Log::MessageBuilder msg(log_);
   1484   msg << name << kNext << tag << kNext;
   1485 
   1486   uint32_t sec, usec;
   1487   if (base::OS::GetUserTime(&sec, &usec) != -1) {
   1488     msg << sec << kNext << usec << kNext;
   1489   }
   1490   msg.AppendFormatString("%.0f",
   1491                          V8::GetCurrentPlatform()->CurrentClockTimeMillis());
   1492   msg.WriteToLogFile();
   1493 }
   1494 
   1495 
   1496 void Logger::SuspectReadEvent(Name* name, Object* obj) {
   1497   if (!log_->IsEnabled() || !FLAG_log_suspect) return;
   1498   Log::MessageBuilder msg(log_);
   1499   String* class_name = obj->IsJSObject()
   1500                            ? JSObject::cast(obj)->class_name()
   1501                            : ReadOnlyRoots(isolate_).empty_string();
   1502   msg << "suspect-read" << kNext << class_name << kNext << name;
   1503   msg.WriteToLogFile();
   1504 }
   1505 
   1506 namespace {
   1507 void AppendFunctionMessage(Log::MessageBuilder& msg, const char* reason,
   1508                            int script_id, double time_delta, int start_position,
   1509                            int end_position, base::ElapsedTimer* timer) {
   1510   msg << "function" << Logger::kNext << reason << Logger::kNext << script_id
   1511       << Logger::kNext << start_position << Logger::kNext << end_position
   1512       << Logger::kNext << time_delta << Logger::kNext
   1513       << timer->Elapsed().InMicroseconds() << Logger::kNext;
   1514 }
   1515 }  // namespace
   1516 
   1517 void Logger::FunctionEvent(const char* reason, int script_id, double time_delta,
   1518                            int start_position, int end_position,
   1519                            String* function_name) {
   1520   if (!log_->IsEnabled() || !FLAG_log_function_events) return;
   1521   Log::MessageBuilder msg(log_);
   1522   AppendFunctionMessage(msg, reason, script_id, time_delta, start_position,
   1523                         end_position, &timer_);
   1524   if (function_name) msg << function_name;
   1525   msg.WriteToLogFile();
   1526 }
   1527 
   1528 void Logger::FunctionEvent(const char* reason, int script_id, double time_delta,
   1529                            int start_position, int end_position,
   1530                            const char* function_name,
   1531                            size_t function_name_length) {
   1532   if (!log_->IsEnabled() || !FLAG_log_function_events) return;
   1533   Log::MessageBuilder msg(log_);
   1534   AppendFunctionMessage(msg, reason, script_id, time_delta, start_position,
   1535                         end_position, &timer_);
   1536   if (function_name_length > 0) {
   1537     msg.AppendString(function_name, function_name_length);
   1538   }
   1539   msg.WriteToLogFile();
   1540 }
   1541 
   1542 void Logger::CompilationCacheEvent(const char* action, const char* cache_type,
   1543                                    SharedFunctionInfo* sfi) {
   1544   if (!log_->IsEnabled() || !FLAG_log_function_events) return;
   1545   Log::MessageBuilder msg(log_);
   1546   int script_id = -1;
   1547   if (sfi->script()->IsScript()) {
   1548     script_id = Script::cast(sfi->script())->id();
   1549   }
   1550   msg << "compilation-cache" << Logger::kNext << action << Logger::kNext
   1551       << cache_type << Logger::kNext << script_id << Logger::kNext
   1552       << sfi->StartPosition() << Logger::kNext << sfi->EndPosition()
   1553       << Logger::kNext << timer_.Elapsed().InMicroseconds();
   1554   msg.WriteToLogFile();
   1555 }
   1556 
   1557 void Logger::ScriptEvent(ScriptEventType type, int script_id) {
   1558   if (!log_->IsEnabled() || !FLAG_log_function_events) return;
   1559   Log::MessageBuilder msg(log_);
   1560   msg << "script" << Logger::kNext;
   1561   switch (type) {
   1562     case ScriptEventType::kReserveId:
   1563       msg << "reserve-id";
   1564       break;
   1565     case ScriptEventType::kCreate:
   1566       msg << "create";
   1567       break;
   1568     case ScriptEventType::kDeserialize:
   1569       msg << "deserialize";
   1570       break;
   1571     case ScriptEventType::kBackgroundCompile:
   1572       msg << "background-compile";
   1573       break;
   1574     case ScriptEventType::kStreamingCompile:
   1575       msg << "streaming-compile";
   1576       break;
   1577   }
   1578   msg << Logger::kNext << script_id << Logger::kNext
   1579       << timer_.Elapsed().InMicroseconds();
   1580   msg.WriteToLogFile();
   1581 }
   1582 
   1583 void Logger::ScriptDetails(Script* script) {
   1584   if (!log_->IsEnabled() || !FLAG_log_function_events) return;
   1585   {
   1586     Log::MessageBuilder msg(log_);
   1587     msg << "script-details" << Logger::kNext << script->id() << Logger::kNext;
   1588     if (script->name()->IsString()) {
   1589       msg << String::cast(script->name());
   1590     }
   1591     msg << Logger::kNext << script->line_offset() << Logger::kNext
   1592         << script->column_offset() << Logger::kNext;
   1593     if (script->source_mapping_url()->IsString()) {
   1594       msg << String::cast(script->source_mapping_url());
   1595     }
   1596     msg.WriteToLogFile();
   1597   }
   1598   EnsureLogScriptSource(script);
   1599 }
   1600 
   1601 bool Logger::EnsureLogScriptSource(Script* script) {
   1602   if (!log_->IsEnabled()) return false;
   1603   Log::MessageBuilder msg(log_);
   1604   // Make sure the script is written to the log file.
   1605   int script_id = script->id();
   1606   if (logged_source_code_.find(script_id) != logged_source_code_.end()) {
   1607     return false;
   1608   }
   1609   // This script has not been logged yet.
   1610   logged_source_code_.insert(script_id);
   1611   Object* source_object = script->source();
   1612   if (!source_object->IsString()) return false;
   1613   String* source_code = String::cast(source_object);
   1614   msg << "script-source" << kNext << script_id << kNext;
   1615 
   1616   // Log the script name.
   1617   if (script->name()->IsString()) {
   1618     msg << String::cast(script->name()) << kNext;
   1619   } else {
   1620     msg << "<unknown>" << kNext;
   1621   }
   1622 
   1623   // Log the source code.
   1624   msg << source_code;
   1625   msg.WriteToLogFile();
   1626   return true;
   1627 }
   1628 
   1629 void Logger::RuntimeCallTimerEvent() {
   1630   RuntimeCallStats* stats = isolate_->counters()->runtime_call_stats();
   1631   RuntimeCallCounter* counter = stats->current_counter();
   1632   if (counter == nullptr) return;
   1633   Log::MessageBuilder msg(log_);
   1634   msg << "active-runtime-timer" << kNext << counter->name();
   1635   msg.WriteToLogFile();
   1636 }
   1637 
   1638 void Logger::TickEvent(v8::TickSample* sample, bool overflow) {
   1639   if (!log_->IsEnabled() || !FLAG_prof_cpp) return;
   1640   if (V8_UNLIKELY(FLAG_runtime_stats ==
   1641                   v8::tracing::TracingCategoryObserver::ENABLED_BY_NATIVE)) {
   1642     RuntimeCallTimerEvent();
   1643   }
   1644   Log::MessageBuilder msg(log_);
   1645   msg << kLogEventsNames[CodeEventListener::TICK_EVENT] << kNext
   1646       << reinterpret_cast<void*>(sample->pc) << kNext
   1647       << timer_.Elapsed().InMicroseconds();
   1648   if (sample->has_external_callback) {
   1649     msg << kNext << 1 << kNext
   1650         << reinterpret_cast<void*>(sample->external_callback_entry);
   1651   } else {
   1652     msg << kNext << 0 << kNext << reinterpret_cast<void*>(sample->tos);
   1653   }
   1654   msg << kNext << static_cast<int>(sample->state);
   1655   if (overflow) msg << kNext << "overflow";
   1656   for (unsigned i = 0; i < sample->frames_count; ++i) {
   1657     msg << kNext << reinterpret_cast<void*>(sample->stack[i]);
   1658   }
   1659   msg.WriteToLogFile();
   1660 }
   1661 
   1662 void Logger::ICEvent(const char* type, bool keyed, Map* map, Object* key,
   1663                      char old_state, char new_state, const char* modifier,
   1664                      const char* slow_stub_reason) {
   1665   if (!log_->IsEnabled() || !FLAG_trace_ic) return;
   1666   Log::MessageBuilder msg(log_);
   1667   if (keyed) msg << "Keyed";
   1668   int line;
   1669   int column;
   1670   Address pc = isolate_->GetAbstractPC(&line, &column);
   1671   msg << type << kNext << reinterpret_cast<void*>(pc) << kNext << line << kNext
   1672       << column << kNext << old_state << kNext << new_state << kNext
   1673       << reinterpret_cast<void*>(map) << kNext;
   1674   if (key->IsSmi()) {
   1675     msg << Smi::ToInt(key);
   1676   } else if (key->IsNumber()) {
   1677     msg << key->Number();
   1678   } else if (key->IsName()) {
   1679     msg << Name::cast(key);
   1680   }
   1681   msg << kNext << modifier << kNext;
   1682   if (slow_stub_reason != nullptr) {
   1683     msg << slow_stub_reason;
   1684   }
   1685   msg.WriteToLogFile();
   1686 }
   1687 
   1688 void Logger::MapEvent(const char* type, Map* from, Map* to, const char* reason,
   1689                       HeapObject* name_or_sfi) {
   1690   DisallowHeapAllocation no_gc;
   1691   if (!log_->IsEnabled() || !FLAG_trace_maps) return;
   1692   if (to) MapDetails(to);
   1693   int line = -1;
   1694   int column = -1;
   1695   Address pc = 0;
   1696 
   1697   if (!isolate_->bootstrapper()->IsActive()) {
   1698     pc = isolate_->GetAbstractPC(&line, &column);
   1699   }
   1700   Log::MessageBuilder msg(log_);
   1701   msg << "map" << kNext << type << kNext << timer_.Elapsed().InMicroseconds()
   1702       << kNext << reinterpret_cast<void*>(from) << kNext
   1703       << reinterpret_cast<void*>(to) << kNext << reinterpret_cast<void*>(pc)
   1704       << kNext << line << kNext << column << kNext << reason << kNext;
   1705 
   1706   if (name_or_sfi) {
   1707     if (name_or_sfi->IsName()) {
   1708       msg << Name::cast(name_or_sfi);
   1709     } else if (name_or_sfi->IsSharedFunctionInfo()) {
   1710       SharedFunctionInfo* sfi = SharedFunctionInfo::cast(name_or_sfi);
   1711       msg << sfi->DebugName();
   1712 #if V8_SFI_HAS_UNIQUE_ID
   1713       msg << " " << sfi->unique_id();
   1714 #endif  // V8_SFI_HAS_UNIQUE_ID
   1715     }
   1716   }
   1717   msg.WriteToLogFile();
   1718 }
   1719 
   1720 void Logger::MapCreate(Map* map) {
   1721   if (!log_->IsEnabled() || !FLAG_trace_maps) return;
   1722   DisallowHeapAllocation no_gc;
   1723   Log::MessageBuilder msg(log_);
   1724   msg << "map-create" << kNext << timer_.Elapsed().InMicroseconds() << kNext
   1725       << reinterpret_cast<void*>(map);
   1726   msg.WriteToLogFile();
   1727 }
   1728 
   1729 void Logger::MapDetails(Map* map) {
   1730   if (!log_->IsEnabled() || !FLAG_trace_maps) return;
   1731   // Disable logging Map details during bootstrapping since we use LogMaps() to
   1732   // log all creating
   1733   if (isolate_->bootstrapper()->IsActive()) return;
   1734   DisallowHeapAllocation no_gc;
   1735   Log::MessageBuilder msg(log_);
   1736   msg << "map-details" << kNext << timer_.Elapsed().InMicroseconds() << kNext
   1737       << reinterpret_cast<void*>(map) << kNext;
   1738   if (FLAG_trace_maps_details) {
   1739     std::ostringstream buffer;
   1740     map->PrintMapDetails(buffer);
   1741     msg << buffer.str().c_str();
   1742   }
   1743   msg.WriteToLogFile();
   1744 }
   1745 
   1746 void Logger::StopProfiler() {
   1747   if (!log_->IsEnabled()) return;
   1748   if (profiler_ != nullptr) {
   1749     profiler_->Pause();
   1750     is_logging_ = false;
   1751     RemoveCodeEventListener(this);
   1752   }
   1753 }
   1754 
   1755 // This function can be called when Log's mutex is acquired,
   1756 // either from main or Profiler's thread.
   1757 void Logger::LogFailure() {
   1758   StopProfiler();
   1759 }
   1760 
   1761 static void AddFunctionAndCode(SharedFunctionInfo* sfi,
   1762                                AbstractCode* code_object,
   1763                                Handle<SharedFunctionInfo>* sfis,
   1764                                Handle<AbstractCode>* code_objects, int offset) {
   1765   if (sfis != nullptr) {
   1766     sfis[offset] = Handle<SharedFunctionInfo>(sfi, sfi->GetIsolate());
   1767   }
   1768   if (code_objects != nullptr) {
   1769     code_objects[offset] = Handle<AbstractCode>(code_object, sfi->GetIsolate());
   1770   }
   1771 }
   1772 
   1773 static int EnumerateCompiledFunctions(Heap* heap,
   1774                                       Handle<SharedFunctionInfo>* sfis,
   1775                                       Handle<AbstractCode>* code_objects) {
   1776   HeapIterator iterator(heap);
   1777   DisallowHeapAllocation no_gc;
   1778   int compiled_funcs_count = 0;
   1779 
   1780   // Iterate the heap to find shared function info objects and record
   1781   // the unoptimized code for them.
   1782   for (HeapObject* obj = iterator.next(); obj != nullptr;
   1783        obj = iterator.next()) {
   1784     if (obj->IsSharedFunctionInfo()) {
   1785       SharedFunctionInfo* sfi = SharedFunctionInfo::cast(obj);
   1786       if (sfi->is_compiled() &&
   1787           (!sfi->script()->IsScript() ||
   1788            Script::cast(sfi->script())->HasValidSource())) {
   1789         AddFunctionAndCode(sfi, AbstractCode::cast(sfi->abstract_code()), sfis,
   1790                            code_objects, compiled_funcs_count);
   1791         ++compiled_funcs_count;
   1792       }
   1793     } else if (obj->IsJSFunction()) {
   1794       // Given that we no longer iterate over all optimized JSFunctions, we need
   1795       // to take care of this here.
   1796       JSFunction* function = JSFunction::cast(obj);
   1797       SharedFunctionInfo* sfi = SharedFunctionInfo::cast(function->shared());
   1798       Object* maybe_script = sfi->script();
   1799       if (maybe_script->IsScript() &&
   1800           !Script::cast(maybe_script)->HasValidSource()) {
   1801         continue;
   1802       }
   1803       // TODO(jarin) This leaves out deoptimized code that might still be on the
   1804       // stack. Also note that we will not log optimized code objects that are
   1805       // only on a type feedback vector. We should make this mroe precise.
   1806       if (function->IsOptimized()) {
   1807         AddFunctionAndCode(sfi, AbstractCode::cast(function->code()), sfis,
   1808                            code_objects, compiled_funcs_count);
   1809         ++compiled_funcs_count;
   1810       }
   1811     }
   1812   }
   1813   return compiled_funcs_count;
   1814 }
   1815 
   1816 static int EnumerateWasmModuleObjects(
   1817     Heap* heap, Handle<WasmModuleObject>* module_objects) {
   1818   HeapIterator iterator(heap);
   1819   DisallowHeapAllocation no_gc;
   1820   int module_objects_count = 0;
   1821 
   1822   for (HeapObject* obj = iterator.next(); obj != nullptr;
   1823        obj = iterator.next()) {
   1824     if (obj->IsWasmModuleObject()) {
   1825       WasmModuleObject* module = WasmModuleObject::cast(obj);
   1826       if (module_objects != nullptr) {
   1827         module_objects[module_objects_count] = handle(module, heap->isolate());
   1828       }
   1829       module_objects_count++;
   1830     }
   1831   }
   1832   return module_objects_count;
   1833 }
   1834 
   1835 void Logger::LogCodeObject(Object* object) {
   1836   existing_code_logger_.LogCodeObject(object);
   1837 }
   1838 
   1839 void Logger::LogCodeObjects() { existing_code_logger_.LogCodeObjects(); }
   1840 
   1841 void Logger::LogBytecodeHandler(interpreter::Bytecode bytecode,
   1842                                 interpreter::OperandScale operand_scale,
   1843                                 Code* code) {
   1844   existing_code_logger_.LogBytecodeHandler(bytecode, operand_scale, code);
   1845 }
   1846 
   1847 void Logger::LogBytecodeHandlers() {
   1848   existing_code_logger_.LogBytecodeHandlers();
   1849 }
   1850 
   1851 void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared,
   1852                                  Handle<AbstractCode> code) {
   1853   existing_code_logger_.LogExistingFunction(shared, code);
   1854 }
   1855 
   1856 void Logger::LogCompiledFunctions() {
   1857   existing_code_logger_.LogCompiledFunctions();
   1858 }
   1859 
   1860 void Logger::LogAccessorCallbacks() {
   1861   Heap* heap = isolate_->heap();
   1862   HeapIterator iterator(heap);
   1863   DisallowHeapAllocation no_gc;
   1864   for (HeapObject* obj = iterator.next(); obj != nullptr;
   1865        obj = iterator.next()) {
   1866     if (!obj->IsAccessorInfo()) continue;
   1867     AccessorInfo* ai = AccessorInfo::cast(obj);
   1868     if (!ai->name()->IsName()) continue;
   1869     Address getter_entry = v8::ToCData<Address>(ai->getter());
   1870     Name* name = Name::cast(ai->name());
   1871     if (getter_entry != 0) {
   1872 #if USES_FUNCTION_DESCRIPTORS
   1873       getter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(getter_entry);
   1874 #endif
   1875       PROFILE(isolate_, GetterCallbackEvent(name, getter_entry));
   1876     }
   1877     Address setter_entry = v8::ToCData<Address>(ai->setter());
   1878     if (setter_entry != 0) {
   1879 #if USES_FUNCTION_DESCRIPTORS
   1880       setter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(setter_entry);
   1881 #endif
   1882       PROFILE(isolate_, SetterCallbackEvent(name, setter_entry));
   1883     }
   1884   }
   1885 }
   1886 
   1887 void Logger::LogMaps() {
   1888   Heap* heap = isolate_->heap();
   1889   HeapIterator iterator(heap);
   1890   DisallowHeapAllocation no_gc;
   1891   for (HeapObject* obj = iterator.next(); obj != nullptr;
   1892        obj = iterator.next()) {
   1893     if (!obj->IsMap()) continue;
   1894     MapDetails(Map::cast(obj));
   1895   }
   1896 }
   1897 
   1898 static void AddIsolateIdIfNeeded(std::ostream& os,  // NOLINT
   1899                                  Isolate* isolate) {
   1900   if (FLAG_logfile_per_isolate) os << "isolate-" << isolate << "-";
   1901 }
   1902 
   1903 
   1904 static void PrepareLogFileName(std::ostream& os,  // NOLINT
   1905                                Isolate* isolate, const char* file_name) {
   1906   int dir_separator_count = 0;
   1907   for (const char* p = file_name; *p; p++) {
   1908     if (base::OS::isDirectorySeparator(*p)) dir_separator_count++;
   1909   }
   1910 
   1911   for (const char* p = file_name; *p; p++) {
   1912     if (dir_separator_count == 0) {
   1913       AddIsolateIdIfNeeded(os, isolate);
   1914       dir_separator_count--;
   1915     }
   1916     if (*p == '%') {
   1917       p++;
   1918       switch (*p) {
   1919         case '\0':
   1920           // If there's a % at the end of the string we back up
   1921           // one character so we can escape the loop properly.
   1922           p--;
   1923           break;
   1924         case 'p':
   1925           os << base::OS::GetCurrentProcessId();
   1926           break;
   1927         case 't':
   1928           // %t expands to the current time in milliseconds.
   1929           os << static_cast<int64_t>(
   1930               V8::GetCurrentPlatform()->CurrentClockTimeMillis());
   1931           break;
   1932         case '%':
   1933           // %% expands (contracts really) to %.
   1934           os << '%';
   1935           break;
   1936         default:
   1937           // All other %'s expand to themselves.
   1938           os << '%' << *p;
   1939           break;
   1940       }
   1941     } else {
   1942       if (base::OS::isDirectorySeparator(*p)) dir_separator_count--;
   1943       os << *p;
   1944     }
   1945   }
   1946 }
   1947 
   1948 
   1949 bool Logger::SetUp(Isolate* isolate) {
   1950   // Tests and EnsureInitialize() can call this twice in a row. It's harmless.
   1951   if (is_initialized_) return true;
   1952   is_initialized_ = true;
   1953 
   1954   std::ostringstream log_file_name;
   1955   std::ostringstream source_log_file_name;
   1956   PrepareLogFileName(log_file_name, isolate, FLAG_logfile);
   1957   log_ = new Log(this, log_file_name.str().c_str());
   1958 
   1959   if (FLAG_perf_basic_prof) {
   1960     perf_basic_logger_ = new PerfBasicLogger(isolate);
   1961     AddCodeEventListener(perf_basic_logger_);
   1962   }
   1963 
   1964   if (FLAG_perf_prof) {
   1965     perf_jit_logger_ = new PerfJitLogger(isolate);
   1966     AddCodeEventListener(perf_jit_logger_);
   1967   }
   1968 
   1969   if (FLAG_ll_prof) {
   1970     ll_logger_ = new LowLevelLogger(isolate, log_file_name.str().c_str());
   1971     AddCodeEventListener(ll_logger_);
   1972   }
   1973 
   1974   ticker_ = new Ticker(isolate, FLAG_prof_sampling_interval);
   1975 
   1976   if (Log::InitLogAtStart()) {
   1977     is_logging_ = true;
   1978   }
   1979 
   1980   timer_.Start();
   1981 
   1982   if (FLAG_prof_cpp) {
   1983     profiler_ = new Profiler(isolate);
   1984     is_logging_ = true;
   1985     profiler_->Engage();
   1986   }
   1987 
   1988   if (is_logging_) {
   1989     AddCodeEventListener(this);
   1990   }
   1991 
   1992   return true;
   1993 }
   1994 
   1995 
   1996 void Logger::SetCodeEventHandler(uint32_t options,
   1997                                  JitCodeEventHandler event_handler) {
   1998   if (jit_logger_) {
   1999     RemoveCodeEventListener(jit_logger_);
   2000     delete jit_logger_;
   2001     jit_logger_ = nullptr;
   2002   }
   2003 
   2004   if (event_handler) {
   2005     jit_logger_ = new JitLogger(isolate_, event_handler);
   2006     AddCodeEventListener(jit_logger_);
   2007     if (options & kJitCodeEventEnumExisting) {
   2008       HandleScope scope(isolate_);
   2009       LogCodeObjects();
   2010       LogCompiledFunctions();
   2011     }
   2012   }
   2013 }
   2014 
   2015 sampler::Sampler* Logger::sampler() {
   2016   return ticker_;
   2017 }
   2018 
   2019 void Logger::StopProfilerThread() {
   2020   if (profiler_ != nullptr) {
   2021     profiler_->Disengage();
   2022     delete profiler_;
   2023     profiler_ = nullptr;
   2024   }
   2025 }
   2026 
   2027 FILE* Logger::TearDown() {
   2028   if (!is_initialized_) return nullptr;
   2029   is_initialized_ = false;
   2030 
   2031   // Stop the profiler thread before closing the file.
   2032   StopProfilerThread();
   2033 
   2034   delete ticker_;
   2035   ticker_ = nullptr;
   2036 
   2037   if (perf_basic_logger_) {
   2038     RemoveCodeEventListener(perf_basic_logger_);
   2039     delete perf_basic_logger_;
   2040     perf_basic_logger_ = nullptr;
   2041   }
   2042 
   2043   if (perf_jit_logger_) {
   2044     RemoveCodeEventListener(perf_jit_logger_);
   2045     delete perf_jit_logger_;
   2046     perf_jit_logger_ = nullptr;
   2047   }
   2048 
   2049   if (ll_logger_) {
   2050     RemoveCodeEventListener(ll_logger_);
   2051     delete ll_logger_;
   2052     ll_logger_ = nullptr;
   2053   }
   2054 
   2055   if (jit_logger_) {
   2056     RemoveCodeEventListener(jit_logger_);
   2057     delete jit_logger_;
   2058     jit_logger_ = nullptr;
   2059   }
   2060 
   2061   return log_->Close();
   2062 }
   2063 
   2064 void ExistingCodeLogger::LogCodeObject(Object* object) {
   2065   AbstractCode* abstract_code = AbstractCode::cast(object);
   2066   CodeEventListener::LogEventsAndTags tag = CodeEventListener::STUB_TAG;
   2067   const char* description = "Unknown code from before profiling";
   2068   switch (abstract_code->kind()) {
   2069     case AbstractCode::INTERPRETED_FUNCTION:
   2070     case AbstractCode::OPTIMIZED_FUNCTION:
   2071       return;  // We log this later using LogCompiledFunctions.
   2072     case AbstractCode::BYTECODE_HANDLER:
   2073       return;  // We log it later by walking the dispatch table.
   2074     case AbstractCode::STUB:
   2075       description =
   2076           CodeStub::MajorName(CodeStub::GetMajorKey(abstract_code->GetCode()));
   2077       if (description == nullptr) description = "A stub from before profiling";
   2078       tag = CodeEventListener::STUB_TAG;
   2079       break;
   2080     case AbstractCode::REGEXP:
   2081       description = "Regular expression code";
   2082       tag = CodeEventListener::REG_EXP_TAG;
   2083       break;
   2084     case AbstractCode::BUILTIN:
   2085       if (Code::cast(object)->is_interpreter_trampoline_builtin() &&
   2086           Code::cast(object) !=
   2087               *BUILTIN_CODE(isolate_, InterpreterEntryTrampoline)) {
   2088         return;
   2089       }
   2090       description =
   2091           isolate_->builtins()->name(abstract_code->GetCode()->builtin_index());
   2092       tag = CodeEventListener::BUILTIN_TAG;
   2093       break;
   2094     case AbstractCode::WASM_FUNCTION:
   2095       description = "A Wasm function";
   2096       tag = CodeEventListener::FUNCTION_TAG;
   2097       break;
   2098     case AbstractCode::JS_TO_WASM_FUNCTION:
   2099       description = "A JavaScript to Wasm adapter";
   2100       tag = CodeEventListener::STUB_TAG;
   2101       break;
   2102     case AbstractCode::WASM_TO_JS_FUNCTION:
   2103       description = "A Wasm to JavaScript adapter";
   2104       tag = CodeEventListener::STUB_TAG;
   2105       break;
   2106     case AbstractCode::WASM_INTERPRETER_ENTRY:
   2107       description = "A Wasm to Interpreter adapter";
   2108       tag = CodeEventListener::STUB_TAG;
   2109       break;
   2110     case AbstractCode::C_WASM_ENTRY:
   2111       description = "A C to Wasm entry stub";
   2112       tag = CodeEventListener::STUB_TAG;
   2113       break;
   2114     case AbstractCode::NUMBER_OF_KINDS:
   2115       UNIMPLEMENTED();
   2116   }
   2117   CALL_CODE_EVENT_HANDLER(CodeCreateEvent(tag, abstract_code, description))
   2118 }
   2119 
   2120 void ExistingCodeLogger::LogCodeObjects() {
   2121   Heap* heap = isolate_->heap();
   2122   HeapIterator iterator(heap);
   2123   DisallowHeapAllocation no_gc;
   2124   for (HeapObject* obj = iterator.next(); obj != nullptr;
   2125        obj = iterator.next()) {
   2126     if (obj->IsCode()) LogCodeObject(obj);
   2127     if (obj->IsBytecodeArray()) LogCodeObject(obj);
   2128   }
   2129 }
   2130 
   2131 void ExistingCodeLogger::LogCompiledFunctions() {
   2132   Heap* heap = isolate_->heap();
   2133   HandleScope scope(isolate_);
   2134   const int compiled_funcs_count =
   2135       EnumerateCompiledFunctions(heap, nullptr, nullptr);
   2136   ScopedVector<Handle<SharedFunctionInfo>> sfis(compiled_funcs_count);
   2137   ScopedVector<Handle<AbstractCode>> code_objects(compiled_funcs_count);
   2138   EnumerateCompiledFunctions(heap, sfis.start(), code_objects.start());
   2139 
   2140   // During iteration, there can be heap allocation due to
   2141   // GetScriptLineNumber call.
   2142   for (int i = 0; i < compiled_funcs_count; ++i) {
   2143     if (sfis[i]->function_data()->IsInterpreterData()) {
   2144       LogExistingFunction(
   2145           sfis[i],
   2146           Handle<AbstractCode>(
   2147               AbstractCode::cast(sfis[i]->InterpreterTrampoline()), isolate_),
   2148           CodeEventListener::INTERPRETED_FUNCTION_TAG);
   2149     }
   2150     if (code_objects[i].is_identical_to(BUILTIN_CODE(isolate_, CompileLazy)))
   2151       continue;
   2152     LogExistingFunction(sfis[i], code_objects[i]);
   2153   }
   2154 
   2155   const int wasm_module_objects_count =
   2156       EnumerateWasmModuleObjects(heap, nullptr);
   2157   std::unique_ptr<Handle<WasmModuleObject>[]> module_objects(
   2158       new Handle<WasmModuleObject>[wasm_module_objects_count]);
   2159   EnumerateWasmModuleObjects(heap, module_objects.get());
   2160   for (int i = 0; i < wasm_module_objects_count; ++i) {
   2161     module_objects[i]->native_module()->LogWasmCodes(isolate_);
   2162   }
   2163 }
   2164 
   2165 void ExistingCodeLogger::LogBytecodeHandler(
   2166     interpreter::Bytecode bytecode, interpreter::OperandScale operand_scale,
   2167     Code* code) {
   2168   std::string bytecode_name =
   2169       interpreter::Bytecodes::ToString(bytecode, operand_scale);
   2170   CALL_CODE_EVENT_HANDLER(
   2171       CodeCreateEvent(CodeEventListener::BYTECODE_HANDLER_TAG,
   2172                       AbstractCode::cast(code), bytecode_name.c_str()))
   2173 }
   2174 
   2175 void ExistingCodeLogger::LogBytecodeHandlers() {
   2176   const interpreter::OperandScale kOperandScales[] = {
   2177 #define VALUE(Name, _) interpreter::OperandScale::k##Name,
   2178       OPERAND_SCALE_LIST(VALUE)
   2179 #undef VALUE
   2180   };
   2181 
   2182   const int last_index = static_cast<int>(interpreter::Bytecode::kLast);
   2183   interpreter::Interpreter* interpreter = isolate_->interpreter();
   2184   for (auto operand_scale : kOperandScales) {
   2185     for (int index = 0; index <= last_index; ++index) {
   2186       interpreter::Bytecode bytecode = interpreter::Bytecodes::FromByte(index);
   2187       if (interpreter::Bytecodes::BytecodeHasHandler(bytecode, operand_scale)) {
   2188         Code* code = interpreter->GetBytecodeHandler(bytecode, operand_scale);
   2189         if (isolate_->heap()->IsDeserializeLazyHandler(code)) continue;
   2190         LogBytecodeHandler(bytecode, operand_scale, code);
   2191       }
   2192     }
   2193   }
   2194 }
   2195 
   2196 void ExistingCodeLogger::LogExistingFunction(
   2197     Handle<SharedFunctionInfo> shared, Handle<AbstractCode> code,
   2198     CodeEventListener::LogEventsAndTags tag) {
   2199   if (shared->script()->IsScript()) {
   2200     Handle<Script> script(Script::cast(shared->script()), isolate_);
   2201     int line_num = Script::GetLineNumber(script, shared->StartPosition()) + 1;
   2202     int column_num =
   2203         Script::GetColumnNumber(script, shared->StartPosition()) + 1;
   2204     if (script->name()->IsString()) {
   2205       Handle<String> script_name(String::cast(script->name()), isolate_);
   2206       if (line_num > 0) {
   2207         CALL_CODE_EVENT_HANDLER(
   2208             CodeCreateEvent(Logger::ToNativeByScript(tag, *script), *code,
   2209                             *shared, *script_name, line_num, column_num))
   2210       } else {
   2211         // Can't distinguish eval and script here, so always use Script.
   2212         CALL_CODE_EVENT_HANDLER(CodeCreateEvent(
   2213             Logger::ToNativeByScript(CodeEventListener::SCRIPT_TAG, *script),
   2214             *code, *shared, *script_name))
   2215       }
   2216     } else {
   2217       CALL_CODE_EVENT_HANDLER(CodeCreateEvent(
   2218           Logger::ToNativeByScript(tag, *script), *code, *shared,
   2219           ReadOnlyRoots(isolate_).empty_string(), line_num, column_num))
   2220     }
   2221   } else if (shared->IsApiFunction()) {
   2222     // API function.
   2223     FunctionTemplateInfo* fun_data = shared->get_api_func_data();
   2224     Object* raw_call_data = fun_data->call_code();
   2225     if (!raw_call_data->IsUndefined(isolate_)) {
   2226       CallHandlerInfo* call_data = CallHandlerInfo::cast(raw_call_data);
   2227       Object* callback_obj = call_data->callback();
   2228       Address entry_point = v8::ToCData<Address>(callback_obj);
   2229 #if USES_FUNCTION_DESCRIPTORS
   2230       entry_point = *FUNCTION_ENTRYPOINT_ADDRESS(entry_point);
   2231 #endif
   2232       CALL_CODE_EVENT_HANDLER(CallbackEvent(shared->DebugName(), entry_point))
   2233     }
   2234   }
   2235 }
   2236 
   2237 #undef CALL_CODE_EVENT_HANDLER
   2238 
   2239 }  // namespace internal
   2240 }  // namespace v8
   2241