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 <sstream>
      9 
     10 #include "src/bailout-reason.h"
     11 #include "src/base/platform/platform.h"
     12 #include "src/bootstrapper.h"
     13 #include "src/code-stubs.h"
     14 #include "src/counters.h"
     15 #include "src/deoptimizer.h"
     16 #include "src/global-handles.h"
     17 #include "src/interpreter/bytecodes.h"
     18 #include "src/interpreter/interpreter.h"
     19 #include "src/libsampler/v8-sampler.h"
     20 #include "src/log-inl.h"
     21 #include "src/log-utils.h"
     22 #include "src/macro-assembler.h"
     23 #include "src/perf-jit.h"
     24 #include "src/profiler/cpu-profiler-inl.h"
     25 #include "src/profiler/profiler-listener.h"
     26 #include "src/runtime-profiler.h"
     27 #include "src/string-stream.h"
     28 #include "src/vm-state-inl.h"
     29 
     30 namespace v8 {
     31 namespace internal {
     32 
     33 
     34 #define DECLARE_EVENT(ignore1, name) name,
     35 static const char* kLogEventsNames[CodeEventListener::NUMBER_OF_LOG_EVENTS] = {
     36     LOG_EVENTS_AND_TAGS_LIST(DECLARE_EVENT)};
     37 #undef DECLARE_EVENT
     38 
     39 static const char* ComputeMarker(SharedFunctionInfo* shared,
     40                                  AbstractCode* code) {
     41   switch (code->kind()) {
     42     case AbstractCode::FUNCTION:
     43     case AbstractCode::INTERPRETED_FUNCTION:
     44       return shared->optimization_disabled() ? "" : "~";
     45     case AbstractCode::OPTIMIZED_FUNCTION:
     46       return "*";
     47     default:
     48       return "";
     49   }
     50 }
     51 
     52 
     53 class CodeEventLogger::NameBuffer {
     54  public:
     55   NameBuffer() { Reset(); }
     56 
     57   void Reset() {
     58     utf8_pos_ = 0;
     59   }
     60 
     61   void Init(CodeEventListener::LogEventsAndTags tag) {
     62     Reset();
     63     AppendBytes(kLogEventsNames[tag]);
     64     AppendByte(':');
     65   }
     66 
     67   void AppendName(Name* name) {
     68     if (name->IsString()) {
     69       AppendString(String::cast(name));
     70     } else {
     71       Symbol* symbol = Symbol::cast(name);
     72       AppendBytes("symbol(");
     73       if (!symbol->name()->IsUndefined(symbol->GetIsolate())) {
     74         AppendBytes("\"");
     75         AppendString(String::cast(symbol->name()));
     76         AppendBytes("\" ");
     77       }
     78       AppendBytes("hash ");
     79       AppendHex(symbol->Hash());
     80       AppendByte(')');
     81     }
     82   }
     83 
     84   void AppendString(String* str) {
     85     if (str == NULL) return;
     86     int uc16_length = Min(str->length(), kUtf16BufferSize);
     87     String::WriteToFlat(str, utf16_buffer, 0, uc16_length);
     88     int previous = unibrow::Utf16::kNoPreviousCharacter;
     89     for (int i = 0; i < uc16_length && utf8_pos_ < kUtf8BufferSize; ++i) {
     90       uc16 c = utf16_buffer[i];
     91       if (c <= unibrow::Utf8::kMaxOneByteChar) {
     92         utf8_buffer_[utf8_pos_++] = static_cast<char>(c);
     93       } else {
     94         int char_length = unibrow::Utf8::Length(c, previous);
     95         if (utf8_pos_ + char_length > kUtf8BufferSize) break;
     96         unibrow::Utf8::Encode(utf8_buffer_ + utf8_pos_, c, previous);
     97         utf8_pos_ += char_length;
     98       }
     99       previous = c;
    100     }
    101   }
    102 
    103   void AppendBytes(const char* bytes, int size) {
    104     size = Min(size, kUtf8BufferSize - utf8_pos_);
    105     MemCopy(utf8_buffer_ + utf8_pos_, bytes, size);
    106     utf8_pos_ += size;
    107   }
    108 
    109   void AppendBytes(const char* bytes) {
    110     AppendBytes(bytes, StrLength(bytes));
    111   }
    112 
    113   void AppendByte(char c) {
    114     if (utf8_pos_ >= kUtf8BufferSize) return;
    115     utf8_buffer_[utf8_pos_++] = c;
    116   }
    117 
    118   void AppendInt(int n) {
    119     int space = kUtf8BufferSize - utf8_pos_;
    120     if (space <= 0) return;
    121     Vector<char> buffer(utf8_buffer_ + utf8_pos_, space);
    122     int size = SNPrintF(buffer, "%d", n);
    123     if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {
    124       utf8_pos_ += size;
    125     }
    126   }
    127 
    128   void AppendHex(uint32_t n) {
    129     int space = kUtf8BufferSize - utf8_pos_;
    130     if (space <= 0) return;
    131     Vector<char> buffer(utf8_buffer_ + utf8_pos_, space);
    132     int size = SNPrintF(buffer, "%x", n);
    133     if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {
    134       utf8_pos_ += size;
    135     }
    136   }
    137 
    138   const char* get() { return utf8_buffer_; }
    139   int size() const { return utf8_pos_; }
    140 
    141  private:
    142   static const int kUtf8BufferSize = 512;
    143   static const int kUtf16BufferSize = kUtf8BufferSize;
    144 
    145   int utf8_pos_;
    146   char utf8_buffer_[kUtf8BufferSize];
    147   uc16 utf16_buffer[kUtf16BufferSize];
    148 };
    149 
    150 
    151 CodeEventLogger::CodeEventLogger() : name_buffer_(new NameBuffer) { }
    152 
    153 CodeEventLogger::~CodeEventLogger() { delete name_buffer_; }
    154 
    155 void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    156                                       AbstractCode* code, const char* comment) {
    157   name_buffer_->Init(tag);
    158   name_buffer_->AppendBytes(comment);
    159   LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());
    160 }
    161 
    162 void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    163                                       AbstractCode* code, Name* name) {
    164   name_buffer_->Init(tag);
    165   name_buffer_->AppendName(name);
    166   LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());
    167 }
    168 
    169 void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    170                                       AbstractCode* code,
    171                                       SharedFunctionInfo* shared, Name* name) {
    172   name_buffer_->Init(tag);
    173   name_buffer_->AppendBytes(ComputeMarker(shared, code));
    174   name_buffer_->AppendName(name);
    175   LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());
    176 }
    177 
    178 void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    179                                       AbstractCode* code,
    180                                       SharedFunctionInfo* shared, Name* source,
    181                                       int line, int column) {
    182   name_buffer_->Init(tag);
    183   name_buffer_->AppendBytes(ComputeMarker(shared, code));
    184   name_buffer_->AppendString(shared->DebugName());
    185   name_buffer_->AppendByte(' ');
    186   if (source->IsString()) {
    187     name_buffer_->AppendString(String::cast(source));
    188   } else {
    189     name_buffer_->AppendBytes("symbol(hash ");
    190     name_buffer_->AppendHex(Name::cast(source)->Hash());
    191     name_buffer_->AppendByte(')');
    192   }
    193   name_buffer_->AppendByte(':');
    194   name_buffer_->AppendInt(line);
    195   LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());
    196 }
    197 
    198 void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    199                                       AbstractCode* code, int args_count) {
    200   name_buffer_->Init(tag);
    201   name_buffer_->AppendInt(args_count);
    202   LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());
    203 }
    204 
    205 void CodeEventLogger::RegExpCodeCreateEvent(AbstractCode* code,
    206                                             String* source) {
    207   name_buffer_->Init(CodeEventListener::REG_EXP_TAG);
    208   name_buffer_->AppendString(source);
    209   LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());
    210 }
    211 
    212 
    213 // Linux perf tool logging support
    214 class PerfBasicLogger : public CodeEventLogger {
    215  public:
    216   PerfBasicLogger();
    217   ~PerfBasicLogger() override;
    218 
    219   void CodeMoveEvent(AbstractCode* from, Address to) override {}
    220   void CodeDisableOptEvent(AbstractCode* code,
    221                            SharedFunctionInfo* shared) override {}
    222 
    223  private:
    224   void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
    225                          const char* name, int length) override;
    226 
    227   // Extension added to V8 log file name to get the low-level log name.
    228   static const char kFilenameFormatString[];
    229   static const int kFilenameBufferPadding;
    230 
    231   FILE* perf_output_handle_;
    232 };
    233 
    234 const char PerfBasicLogger::kFilenameFormatString[] = "/tmp/perf-%d.map";
    235 // Extra space for the PID in the filename
    236 const int PerfBasicLogger::kFilenameBufferPadding = 16;
    237 
    238 PerfBasicLogger::PerfBasicLogger()
    239     : perf_output_handle_(NULL) {
    240   // Open the perf JIT dump file.
    241   int bufferSize = sizeof(kFilenameFormatString) + kFilenameBufferPadding;
    242   ScopedVector<char> perf_dump_name(bufferSize);
    243   int size = SNPrintF(
    244       perf_dump_name,
    245       kFilenameFormatString,
    246       base::OS::GetCurrentProcessId());
    247   CHECK_NE(size, -1);
    248   perf_output_handle_ =
    249       base::OS::FOpen(perf_dump_name.start(), base::OS::LogFileOpenMode);
    250   CHECK_NOT_NULL(perf_output_handle_);
    251   setvbuf(perf_output_handle_, NULL, _IOLBF, 0);
    252 }
    253 
    254 
    255 PerfBasicLogger::~PerfBasicLogger() {
    256   fclose(perf_output_handle_);
    257   perf_output_handle_ = NULL;
    258 }
    259 
    260 void PerfBasicLogger::LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo*,
    261                                         const char* name, int length) {
    262   if (FLAG_perf_basic_prof_only_functions &&
    263       (code->kind() != AbstractCode::FUNCTION &&
    264        code->kind() != AbstractCode::INTERPRETED_FUNCTION &&
    265        code->kind() != AbstractCode::OPTIMIZED_FUNCTION)) {
    266     return;
    267   }
    268 
    269   // Linux perf expects hex literals without a leading 0x, while some
    270   // implementations of printf might prepend one when using the %p format
    271   // for pointers, leading to wrongly formatted JIT symbols maps.
    272   //
    273   // Instead, we use V8PRIxPTR format string and cast pointer to uintpr_t,
    274   // so that we have control over the exact output format.
    275   base::OS::FPrint(perf_output_handle_, "%" V8PRIxPTR " %x %.*s\n",
    276                    reinterpret_cast<uintptr_t>(code->instruction_start()),
    277                    code->instruction_size(), length, name);
    278 }
    279 
    280 // Low-level logging support.
    281 #define LL_LOG(Call) if (ll_logger_) ll_logger_->Call;
    282 
    283 class LowLevelLogger : public CodeEventLogger {
    284  public:
    285   explicit LowLevelLogger(const char* file_name);
    286   ~LowLevelLogger() override;
    287 
    288   void CodeMoveEvent(AbstractCode* from, Address to) override;
    289   void CodeDisableOptEvent(AbstractCode* code,
    290                            SharedFunctionInfo* shared) override {}
    291   void SnapshotPositionEvent(HeapObject* obj, int pos);
    292   void CodeMovingGCEvent() override;
    293 
    294  private:
    295   void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
    296                          const char* name, int length) override;
    297 
    298   // Low-level profiling event structures.
    299   struct CodeCreateStruct {
    300     static const char kTag = 'C';
    301 
    302     int32_t name_size;
    303     Address code_address;
    304     int32_t code_size;
    305   };
    306 
    307 
    308   struct CodeMoveStruct {
    309     static const char kTag = 'M';
    310 
    311     Address from_address;
    312     Address to_address;
    313   };
    314 
    315 
    316   static const char kCodeMovingGCTag = 'G';
    317 
    318 
    319   // Extension added to V8 log file name to get the low-level log name.
    320   static const char kLogExt[];
    321 
    322   void LogCodeInfo();
    323   void LogWriteBytes(const char* bytes, int size);
    324 
    325   template <typename T>
    326   void LogWriteStruct(const T& s) {
    327     char tag = T::kTag;
    328     LogWriteBytes(reinterpret_cast<const char*>(&tag), sizeof(tag));
    329     LogWriteBytes(reinterpret_cast<const char*>(&s), sizeof(s));
    330   }
    331 
    332   FILE* ll_output_handle_;
    333 };
    334 
    335 const char LowLevelLogger::kLogExt[] = ".ll";
    336 
    337 LowLevelLogger::LowLevelLogger(const char* name)
    338     : ll_output_handle_(NULL) {
    339   // Open the low-level log file.
    340   size_t len = strlen(name);
    341   ScopedVector<char> ll_name(static_cast<int>(len + sizeof(kLogExt)));
    342   MemCopy(ll_name.start(), name, len);
    343   MemCopy(ll_name.start() + len, kLogExt, sizeof(kLogExt));
    344   ll_output_handle_ =
    345       base::OS::FOpen(ll_name.start(), base::OS::LogFileOpenMode);
    346   setvbuf(ll_output_handle_, NULL, _IOLBF, 0);
    347 
    348   LogCodeInfo();
    349 }
    350 
    351 
    352 LowLevelLogger::~LowLevelLogger() {
    353   fclose(ll_output_handle_);
    354   ll_output_handle_ = NULL;
    355 }
    356 
    357 
    358 void LowLevelLogger::LogCodeInfo() {
    359 #if V8_TARGET_ARCH_IA32
    360   const char arch[] = "ia32";
    361 #elif V8_TARGET_ARCH_X64 && V8_TARGET_ARCH_64_BIT
    362   const char arch[] = "x64";
    363 #elif V8_TARGET_ARCH_X64 && V8_TARGET_ARCH_32_BIT
    364   const char arch[] = "x32";
    365 #elif V8_TARGET_ARCH_ARM
    366   const char arch[] = "arm";
    367 #elif V8_TARGET_ARCH_PPC
    368   const char arch[] = "ppc";
    369 #elif V8_TARGET_ARCH_MIPS
    370   const char arch[] = "mips";
    371 #elif V8_TARGET_ARCH_X87
    372   const char arch[] = "x87";
    373 #elif V8_TARGET_ARCH_ARM64
    374   const char arch[] = "arm64";
    375 #elif V8_TARGET_ARCH_S390
    376   const char arch[] = "s390";
    377 #else
    378   const char arch[] = "unknown";
    379 #endif
    380   LogWriteBytes(arch, sizeof(arch));
    381 }
    382 
    383 void LowLevelLogger::LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo*,
    384                                        const char* name, int length) {
    385   CodeCreateStruct event;
    386   event.name_size = length;
    387   event.code_address = code->instruction_start();
    388   event.code_size = code->instruction_size();
    389   LogWriteStruct(event);
    390   LogWriteBytes(name, length);
    391   LogWriteBytes(
    392       reinterpret_cast<const char*>(code->instruction_start()),
    393       code->instruction_size());
    394 }
    395 
    396 void LowLevelLogger::CodeMoveEvent(AbstractCode* from, Address to) {
    397   CodeMoveStruct event;
    398   event.from_address = from->instruction_start();
    399   size_t header_size = from->instruction_start() - from->address();
    400   event.to_address = to + header_size;
    401   LogWriteStruct(event);
    402 }
    403 
    404 
    405 void LowLevelLogger::LogWriteBytes(const char* bytes, int size) {
    406   size_t rv = fwrite(bytes, 1, size, ll_output_handle_);
    407   DCHECK(static_cast<size_t>(size) == rv);
    408   USE(rv);
    409 }
    410 
    411 
    412 void LowLevelLogger::CodeMovingGCEvent() {
    413   const char tag = kCodeMovingGCTag;
    414 
    415   LogWriteBytes(&tag, sizeof(tag));
    416 }
    417 
    418 
    419 #define JIT_LOG(Call) if (jit_logger_) jit_logger_->Call;
    420 
    421 
    422 class JitLogger : public CodeEventLogger {
    423  public:
    424   explicit JitLogger(JitCodeEventHandler code_event_handler);
    425 
    426   void CodeMoveEvent(AbstractCode* from, Address to) override;
    427   void CodeDisableOptEvent(AbstractCode* code,
    428                            SharedFunctionInfo* shared) override {}
    429   void AddCodeLinePosInfoEvent(void* jit_handler_data, int pc_offset,
    430                                int position,
    431                                JitCodeEvent::PositionType position_type);
    432 
    433   void* StartCodePosInfoEvent();
    434   void EndCodePosInfoEvent(AbstractCode* code, void* jit_handler_data);
    435 
    436  private:
    437   void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
    438                          const char* name, int length) override;
    439 
    440   JitCodeEventHandler code_event_handler_;
    441   base::Mutex logger_mutex_;
    442 };
    443 
    444 
    445 JitLogger::JitLogger(JitCodeEventHandler code_event_handler)
    446     : code_event_handler_(code_event_handler) {
    447 }
    448 
    449 void JitLogger::LogRecordedBuffer(AbstractCode* code,
    450                                   SharedFunctionInfo* shared, const char* name,
    451                                   int length) {
    452   JitCodeEvent event;
    453   memset(&event, 0, sizeof(event));
    454   event.type = JitCodeEvent::CODE_ADDED;
    455   event.code_start = code->instruction_start();
    456   event.code_len = code->instruction_size();
    457   Handle<SharedFunctionInfo> shared_function_handle;
    458   if (shared && shared->script()->IsScript()) {
    459     shared_function_handle = Handle<SharedFunctionInfo>(shared);
    460   }
    461   event.script = ToApiHandle<v8::UnboundScript>(shared_function_handle);
    462   event.name.str = name;
    463   event.name.len = length;
    464   code_event_handler_(&event);
    465 }
    466 
    467 void JitLogger::CodeMoveEvent(AbstractCode* from, Address to) {
    468   base::LockGuard<base::Mutex> guard(&logger_mutex_);
    469 
    470   JitCodeEvent event;
    471   event.type = JitCodeEvent::CODE_MOVED;
    472   event.code_start = from->instruction_start();
    473   event.code_len = from->instruction_size();
    474 
    475   // Calculate the header size.
    476   const size_t header_size = from->instruction_start() - from->address();
    477 
    478   // Calculate the new start address of the instructions.
    479   event.new_code_start = to + header_size;
    480 
    481   code_event_handler_(&event);
    482 }
    483 
    484 void JitLogger::AddCodeLinePosInfoEvent(
    485     void* jit_handler_data,
    486     int pc_offset,
    487     int position,
    488     JitCodeEvent::PositionType position_type) {
    489   JitCodeEvent event;
    490   memset(&event, 0, sizeof(event));
    491   event.type = JitCodeEvent::CODE_ADD_LINE_POS_INFO;
    492   event.user_data = jit_handler_data;
    493   event.line_info.offset = pc_offset;
    494   event.line_info.pos = position;
    495   event.line_info.position_type = position_type;
    496 
    497   code_event_handler_(&event);
    498 }
    499 
    500 
    501 void* JitLogger::StartCodePosInfoEvent() {
    502   JitCodeEvent event;
    503   memset(&event, 0, sizeof(event));
    504   event.type = JitCodeEvent::CODE_START_LINE_INFO_RECORDING;
    505 
    506   code_event_handler_(&event);
    507   return event.user_data;
    508 }
    509 
    510 void JitLogger::EndCodePosInfoEvent(AbstractCode* code,
    511                                     void* jit_handler_data) {
    512   JitCodeEvent event;
    513   memset(&event, 0, sizeof(event));
    514   event.type = JitCodeEvent::CODE_END_LINE_INFO_RECORDING;
    515   event.code_start = code->instruction_start();
    516   event.user_data = jit_handler_data;
    517 
    518   code_event_handler_(&event);
    519 }
    520 
    521 
    522 // TODO(lpy): Keeping sampling thread inside V8 is a workaround currently,
    523 // the reason is to reduce code duplication during migration to sampler library,
    524 // sampling thread, as well as the sampler, will be moved to D8 eventually.
    525 class SamplingThread : public base::Thread {
    526  public:
    527   static const int kSamplingThreadStackSize = 64 * KB;
    528 
    529   SamplingThread(sampler::Sampler* sampler, int interval)
    530       : base::Thread(base::Thread::Options("SamplingThread",
    531                                            kSamplingThreadStackSize)),
    532         sampler_(sampler),
    533         interval_(interval) {}
    534   void Run() override {
    535     while (sampler_->IsProfiling()) {
    536       sampler_->DoSample();
    537       base::OS::Sleep(base::TimeDelta::FromMilliseconds(interval_));
    538     }
    539   }
    540 
    541  private:
    542   sampler::Sampler* sampler_;
    543   const int interval_;
    544 };
    545 
    546 
    547 // The Profiler samples pc and sp values for the main thread.
    548 // Each sample is appended to a circular buffer.
    549 // An independent thread removes data and writes it to the log.
    550 // This design minimizes the time spent in the sampler.
    551 //
    552 class Profiler: public base::Thread {
    553  public:
    554   explicit Profiler(Isolate* isolate);
    555   void Engage();
    556   void Disengage();
    557 
    558   // Inserts collected profiling data into buffer.
    559   void Insert(TickSample* sample) {
    560     if (paused_)
    561       return;
    562 
    563     if (Succ(head_) == static_cast<int>(base::NoBarrier_Load(&tail_))) {
    564       overflow_ = true;
    565     } else {
    566       buffer_[head_] = *sample;
    567       head_ = Succ(head_);
    568       buffer_semaphore_.Signal();  // Tell we have an element.
    569     }
    570   }
    571 
    572   virtual void Run();
    573 
    574   // Pause and Resume TickSample data collection.
    575   void pause() { paused_ = true; }
    576   void resume() { paused_ = false; }
    577 
    578  private:
    579   // Waits for a signal and removes profiling data.
    580   bool Remove(TickSample* sample) {
    581     buffer_semaphore_.Wait();  // Wait for an element.
    582     *sample = buffer_[base::NoBarrier_Load(&tail_)];
    583     bool result = overflow_;
    584     base::NoBarrier_Store(&tail_, static_cast<base::Atomic32>(
    585                                       Succ(base::NoBarrier_Load(&tail_))));
    586     overflow_ = false;
    587     return result;
    588   }
    589 
    590   // Returns the next index in the cyclic buffer.
    591   int Succ(int index) { return (index + 1) % kBufferSize; }
    592 
    593   Isolate* isolate_;
    594   // Cyclic buffer for communicating profiling samples
    595   // between the signal handler and the worker thread.
    596   static const int kBufferSize = 128;
    597   TickSample buffer_[kBufferSize];  // Buffer storage.
    598   int head_;  // Index to the buffer head.
    599   base::Atomic32 tail_;             // Index to the buffer tail.
    600   bool overflow_;  // Tell whether a buffer overflow has occurred.
    601   // Sempahore used for buffer synchronization.
    602   base::Semaphore buffer_semaphore_;
    603 
    604   // Tells whether profiler is engaged, that is, processing thread is stated.
    605   bool engaged_;
    606 
    607   // Tells whether worker thread should continue running.
    608   base::Atomic32 running_;
    609 
    610   // Tells whether we are currently recording tick samples.
    611   bool paused_;
    612 };
    613 
    614 
    615 //
    616 // Ticker used to provide ticks to the profiler and the sliding state
    617 // window.
    618 //
    619 class Ticker: public sampler::Sampler {
    620  public:
    621   Ticker(Isolate* isolate, int interval):
    622       sampler::Sampler(reinterpret_cast<v8::Isolate*>(isolate)),
    623       profiler_(NULL),
    624       sampling_thread_(new SamplingThread(this, interval)) {}
    625 
    626   ~Ticker() {
    627     if (IsActive()) Stop();
    628     delete sampling_thread_;
    629   }
    630 
    631   void SetProfiler(Profiler* profiler) {
    632     DCHECK(profiler_ == NULL);
    633     profiler_ = profiler;
    634     IncreaseProfilingDepth();
    635     if (!IsActive()) Start();
    636     sampling_thread_->StartSynchronously();
    637   }
    638 
    639   void ClearProfiler() {
    640     profiler_ = NULL;
    641     if (IsActive()) Stop();
    642     DecreaseProfilingDepth();
    643     sampling_thread_->Join();
    644   }
    645 
    646   void SampleStack(const v8::RegisterState& state) override {
    647     v8::Isolate* v8_isolate = isolate();
    648     Isolate* isolate = reinterpret_cast<Isolate*>(v8_isolate);
    649 #if defined(USE_SIMULATOR)
    650     SimulatorHelper::FillRegisters(isolate,
    651                                    const_cast<v8::RegisterState*>(&state));
    652 #endif
    653     TickSample* sample = isolate->cpu_profiler()->StartTickSample();
    654     TickSample sample_obj;
    655     if (sample == NULL) sample = &sample_obj;
    656     sample->Init(isolate, state, TickSample::kIncludeCEntryFrame, true);
    657     if (is_counting_samples_ && !sample->timestamp.IsNull()) {
    658       if (sample->state == JS) ++js_sample_count_;
    659       if (sample->state == EXTERNAL) ++external_sample_count_;
    660     }
    661     if (profiler_) profiler_->Insert(sample);
    662     if (sample != &sample_obj) {
    663       isolate->cpu_profiler()->FinishTickSample();
    664     }
    665   }
    666 
    667  private:
    668   Profiler* profiler_;
    669   SamplingThread* sampling_thread_;
    670 };
    671 
    672 
    673 //
    674 // Profiler implementation.
    675 //
    676 Profiler::Profiler(Isolate* isolate)
    677     : base::Thread(Options("v8:Profiler")),
    678       isolate_(isolate),
    679       head_(0),
    680       overflow_(false),
    681       buffer_semaphore_(0),
    682       engaged_(false),
    683       paused_(false) {
    684   base::NoBarrier_Store(&tail_, 0);
    685   base::NoBarrier_Store(&running_, 0);
    686 }
    687 
    688 
    689 void Profiler::Engage() {
    690   if (engaged_) return;
    691   engaged_ = true;
    692 
    693   std::vector<base::OS::SharedLibraryAddress> addresses =
    694       base::OS::GetSharedLibraryAddresses();
    695   for (size_t i = 0; i < addresses.size(); ++i) {
    696     LOG(isolate_,
    697         SharedLibraryEvent(addresses[i].library_path, addresses[i].start,
    698                            addresses[i].end, addresses[i].aslr_slide));
    699   }
    700 
    701   // Start thread processing the profiler buffer.
    702   base::NoBarrier_Store(&running_, 1);
    703   Start();
    704 
    705   // Register to get ticks.
    706   Logger* logger = isolate_->logger();
    707   logger->ticker_->SetProfiler(this);
    708 
    709   logger->ProfilerBeginEvent();
    710 }
    711 
    712 
    713 void Profiler::Disengage() {
    714   if (!engaged_) return;
    715 
    716   // Stop receiving ticks.
    717   isolate_->logger()->ticker_->ClearProfiler();
    718 
    719   // Terminate the worker thread by setting running_ to false,
    720   // inserting a fake element in the queue and then wait for
    721   // the thread to terminate.
    722   base::NoBarrier_Store(&running_, 0);
    723   TickSample sample;
    724   // Reset 'paused_' flag, otherwise semaphore may not be signalled.
    725   resume();
    726   Insert(&sample);
    727   Join();
    728 
    729   LOG(isolate_, UncheckedStringEvent("profiler", "end"));
    730 }
    731 
    732 
    733 void Profiler::Run() {
    734   TickSample sample;
    735   bool overflow = Remove(&sample);
    736   while (base::NoBarrier_Load(&running_)) {
    737     LOG(isolate_, TickEvent(&sample, overflow));
    738     overflow = Remove(&sample);
    739   }
    740 }
    741 
    742 
    743 //
    744 // Logger class implementation.
    745 //
    746 
    747 Logger::Logger(Isolate* isolate)
    748     : isolate_(isolate),
    749       ticker_(NULL),
    750       profiler_(NULL),
    751       log_events_(NULL),
    752       is_logging_(false),
    753       log_(new Log(this)),
    754       perf_basic_logger_(NULL),
    755       perf_jit_logger_(NULL),
    756       ll_logger_(NULL),
    757       jit_logger_(NULL),
    758       listeners_(5),
    759       is_initialized_(false) {}
    760 
    761 Logger::~Logger() {
    762   delete log_;
    763 }
    764 
    765 void Logger::addCodeEventListener(CodeEventListener* listener) {
    766   bool result = isolate_->code_event_dispatcher()->AddListener(listener);
    767   USE(result);
    768   DCHECK(result);
    769 }
    770 
    771 void Logger::removeCodeEventListener(CodeEventListener* listener) {
    772   isolate_->code_event_dispatcher()->RemoveListener(listener);
    773 }
    774 
    775 void Logger::ProfilerBeginEvent() {
    776   if (!log_->IsEnabled()) return;
    777   Log::MessageBuilder msg(log_);
    778   msg.Append("profiler,\"begin\",%d", kSamplingIntervalMs);
    779   msg.WriteToLogFile();
    780 }
    781 
    782 
    783 void Logger::StringEvent(const char* name, const char* value) {
    784   if (FLAG_log) UncheckedStringEvent(name, value);
    785 }
    786 
    787 
    788 void Logger::UncheckedStringEvent(const char* name, const char* value) {
    789   if (!log_->IsEnabled()) return;
    790   Log::MessageBuilder msg(log_);
    791   msg.Append("%s,\"%s\"", name, value);
    792   msg.WriteToLogFile();
    793 }
    794 
    795 
    796 void Logger::IntEvent(const char* name, int value) {
    797   if (FLAG_log) UncheckedIntEvent(name, value);
    798 }
    799 
    800 
    801 void Logger::IntPtrTEvent(const char* name, intptr_t value) {
    802   if (FLAG_log) UncheckedIntPtrTEvent(name, value);
    803 }
    804 
    805 
    806 void Logger::UncheckedIntEvent(const char* name, int value) {
    807   if (!log_->IsEnabled()) return;
    808   Log::MessageBuilder msg(log_);
    809   msg.Append("%s,%d", name, value);
    810   msg.WriteToLogFile();
    811 }
    812 
    813 
    814 void Logger::UncheckedIntPtrTEvent(const char* name, intptr_t value) {
    815   if (!log_->IsEnabled()) return;
    816   Log::MessageBuilder msg(log_);
    817   msg.Append("%s,%" V8PRIdPTR, name, value);
    818   msg.WriteToLogFile();
    819 }
    820 
    821 
    822 void Logger::HandleEvent(const char* name, Object** location) {
    823   if (!log_->IsEnabled() || !FLAG_log_handles) return;
    824   Log::MessageBuilder msg(log_);
    825   msg.Append("%s,%p", name, static_cast<void*>(location));
    826   msg.WriteToLogFile();
    827 }
    828 
    829 
    830 // ApiEvent is private so all the calls come from the Logger class.  It is the
    831 // caller's responsibility to ensure that log is enabled and that
    832 // FLAG_log_api is true.
    833 void Logger::ApiEvent(const char* format, ...) {
    834   DCHECK(log_->IsEnabled() && FLAG_log_api);
    835   Log::MessageBuilder msg(log_);
    836   va_list ap;
    837   va_start(ap, format);
    838   msg.AppendVA(format, ap);
    839   va_end(ap);
    840   msg.WriteToLogFile();
    841 }
    842 
    843 
    844 void Logger::ApiSecurityCheck() {
    845   if (!log_->IsEnabled() || !FLAG_log_api) return;
    846   ApiEvent("api,check-security");
    847 }
    848 
    849 void Logger::SharedLibraryEvent(const std::string& library_path,
    850                                 uintptr_t start, uintptr_t end,
    851                                 intptr_t aslr_slide) {
    852   if (!log_->IsEnabled() || !FLAG_prof_cpp) return;
    853   Log::MessageBuilder msg(log_);
    854   msg.Append("shared-library,\"%s\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR
    855              ",%" V8PRIdPTR,
    856              library_path.c_str(), start, end, aslr_slide);
    857   msg.WriteToLogFile();
    858 }
    859 
    860 
    861 void Logger::CodeDeoptEvent(Code* code, Address pc, int fp_to_sp_delta) {
    862   if (!log_->IsEnabled() || !FLAG_log_internal_timer_events) return;
    863   Log::MessageBuilder msg(log_);
    864   int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());
    865   msg.Append("code-deopt,%d,%d", since_epoch, code->CodeSize());
    866   msg.WriteToLogFile();
    867 }
    868 
    869 
    870 void Logger::CurrentTimeEvent() {
    871   if (!log_->IsEnabled()) return;
    872   DCHECK(FLAG_log_timer_events || FLAG_prof_cpp);
    873   Log::MessageBuilder msg(log_);
    874   int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());
    875   msg.Append("current-time,%d", since_epoch);
    876   msg.WriteToLogFile();
    877 }
    878 
    879 
    880 void Logger::TimerEvent(Logger::StartEnd se, const char* name) {
    881   if (!log_->IsEnabled()) return;
    882   DCHECK(FLAG_log_internal_timer_events);
    883   Log::MessageBuilder msg(log_);
    884   int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());
    885   const char* format = (se == START) ? "timer-event-start,\"%s\",%ld"
    886                                      : "timer-event-end,\"%s\",%ld";
    887   msg.Append(format, name, since_epoch);
    888   msg.WriteToLogFile();
    889 }
    890 
    891 
    892 void Logger::EnterExternal(Isolate* isolate) {
    893   LOG(isolate, TimerEvent(START, TimerEventExternal::name()));
    894   DCHECK(isolate->current_vm_state() == JS);
    895   isolate->set_current_vm_state(EXTERNAL);
    896 }
    897 
    898 
    899 void Logger::LeaveExternal(Isolate* isolate) {
    900   LOG(isolate, TimerEvent(END, TimerEventExternal::name()));
    901   DCHECK(isolate->current_vm_state() == EXTERNAL);
    902   isolate->set_current_vm_state(JS);
    903 }
    904 
    905 
    906 template <class TimerEvent>
    907 void TimerEventScope<TimerEvent>::LogTimerEvent(Logger::StartEnd se) {
    908   Logger::CallEventLogger(isolate_, TimerEvent::name(), se,
    909                           TimerEvent::expose_to_api());
    910 }
    911 
    912 
    913 // Instantiate template methods.
    914 #define V(TimerName, expose)                                           \
    915   template void TimerEventScope<TimerEvent##TimerName>::LogTimerEvent( \
    916       Logger::StartEnd se);
    917 TIMER_EVENTS_LIST(V)
    918 #undef V
    919 
    920 
    921 namespace {
    922 // Emits the source code of a regexp. Used by regexp events.
    923 void LogRegExpSource(Handle<JSRegExp> regexp, Isolate* isolate,
    924                      Log::MessageBuilder* msg) {
    925   // Prints "/" + re.source + "/" +
    926   //      (re.global?"g":"") + (re.ignorecase?"i":"") + (re.multiline?"m":"")
    927 
    928   Handle<Object> source =
    929       JSReceiver::GetProperty(isolate, regexp, "source").ToHandleChecked();
    930   if (!source->IsString()) {
    931     msg->Append("no source");
    932     return;
    933   }
    934 
    935   switch (regexp->TypeTag()) {
    936     case JSRegExp::ATOM:
    937       msg->Append('a');
    938       break;
    939     default:
    940       break;
    941   }
    942   msg->Append('/');
    943   msg->AppendDetailed(*Handle<String>::cast(source), false);
    944   msg->Append('/');
    945 
    946   // global flag
    947   Handle<Object> global =
    948       JSReceiver::GetProperty(isolate, regexp, "global").ToHandleChecked();
    949   if (global->IsTrue(isolate)) {
    950     msg->Append('g');
    951   }
    952   // ignorecase flag
    953   Handle<Object> ignorecase =
    954       JSReceiver::GetProperty(isolate, regexp, "ignoreCase").ToHandleChecked();
    955   if (ignorecase->IsTrue(isolate)) {
    956     msg->Append('i');
    957   }
    958   // multiline flag
    959   Handle<Object> multiline =
    960       JSReceiver::GetProperty(isolate, regexp, "multiline").ToHandleChecked();
    961   if (multiline->IsTrue(isolate)) {
    962     msg->Append('m');
    963   }
    964 }
    965 }  // namespace
    966 
    967 
    968 void Logger::RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache) {
    969   if (!log_->IsEnabled() || !FLAG_log_regexp) return;
    970   Log::MessageBuilder msg(log_);
    971   msg.Append("regexp-compile,");
    972   LogRegExpSource(regexp, isolate_, &msg);
    973   msg.Append(in_cache ? ",hit" : ",miss");
    974   msg.WriteToLogFile();
    975 }
    976 
    977 
    978 void Logger::ApiNamedPropertyAccess(const char* tag,
    979                                     JSObject* holder,
    980                                     Object* name) {
    981   DCHECK(name->IsName());
    982   if (!log_->IsEnabled() || !FLAG_log_api) return;
    983   String* class_name_obj = holder->class_name();
    984   base::SmartArrayPointer<char> class_name =
    985       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    986   if (name->IsString()) {
    987     base::SmartArrayPointer<char> property_name =
    988         String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    989     ApiEvent("api,%s,\"%s\",\"%s\"", tag, class_name.get(),
    990              property_name.get());
    991   } else {
    992     Symbol* symbol = Symbol::cast(name);
    993     uint32_t hash = symbol->Hash();
    994     if (symbol->name()->IsUndefined(symbol->GetIsolate())) {
    995       ApiEvent("api,%s,\"%s\",symbol(hash %x)", tag, class_name.get(), hash);
    996     } else {
    997       base::SmartArrayPointer<char> str =
    998           String::cast(symbol->name())
    999               ->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1000       ApiEvent("api,%s,\"%s\",symbol(\"%s\" hash %x)", tag, class_name.get(),
   1001                str.get(), hash);
   1002     }
   1003   }
   1004 }
   1005 
   1006 void Logger::ApiIndexedPropertyAccess(const char* tag,
   1007                                       JSObject* holder,
   1008                                       uint32_t index) {
   1009   if (!log_->IsEnabled() || !FLAG_log_api) return;
   1010   String* class_name_obj = holder->class_name();
   1011   base::SmartArrayPointer<char> class_name =
   1012       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1013   ApiEvent("api,%s,\"%s\",%u", tag, class_name.get(), index);
   1014 }
   1015 
   1016 
   1017 void Logger::ApiObjectAccess(const char* tag, JSObject* object) {
   1018   if (!log_->IsEnabled() || !FLAG_log_api) return;
   1019   String* class_name_obj = object->class_name();
   1020   base::SmartArrayPointer<char> class_name =
   1021       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1022   ApiEvent("api,%s,\"%s\"", tag, class_name.get());
   1023 }
   1024 
   1025 
   1026 void Logger::ApiEntryCall(const char* name) {
   1027   if (!log_->IsEnabled() || !FLAG_log_api) return;
   1028   ApiEvent("api,%s", name);
   1029 }
   1030 
   1031 
   1032 void Logger::NewEvent(const char* name, void* object, size_t size) {
   1033   if (!log_->IsEnabled() || !FLAG_log) return;
   1034   Log::MessageBuilder msg(log_);
   1035   msg.Append("new,%s,%p,%u", name, object, static_cast<unsigned int>(size));
   1036   msg.WriteToLogFile();
   1037 }
   1038 
   1039 
   1040 void Logger::DeleteEvent(const char* name, void* object) {
   1041   if (!log_->IsEnabled() || !FLAG_log) return;
   1042   Log::MessageBuilder msg(log_);
   1043   msg.Append("delete,%s,%p", name, object);
   1044   msg.WriteToLogFile();
   1045 }
   1046 
   1047 
   1048 void Logger::CallbackEventInternal(const char* prefix, Name* name,
   1049                                    Address entry_point) {
   1050   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1051   Log::MessageBuilder msg(log_);
   1052   msg.Append("%s,%s,-2,",
   1053              kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT],
   1054              kLogEventsNames[CodeEventListener::CALLBACK_TAG]);
   1055   msg.AppendAddress(entry_point);
   1056   if (name->IsString()) {
   1057     base::SmartArrayPointer<char> str =
   1058         String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1059     msg.Append(",1,\"%s%s\"", prefix, str.get());
   1060   } else {
   1061     Symbol* symbol = Symbol::cast(name);
   1062     if (symbol->name()->IsUndefined(symbol->GetIsolate())) {
   1063       msg.Append(",1,symbol(hash %x)", symbol->Hash());
   1064     } else {
   1065       base::SmartArrayPointer<char> str =
   1066           String::cast(symbol->name())
   1067               ->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1068       msg.Append(",1,symbol(\"%s%s\" hash %x)", prefix, str.get(),
   1069                  symbol->Hash());
   1070     }
   1071   }
   1072   msg.WriteToLogFile();
   1073 }
   1074 
   1075 
   1076 void Logger::CallbackEvent(Name* name, Address entry_point) {
   1077   CallbackEventInternal("", name, entry_point);
   1078 }
   1079 
   1080 
   1081 void Logger::GetterCallbackEvent(Name* name, Address entry_point) {
   1082   CallbackEventInternal("get ", name, entry_point);
   1083 }
   1084 
   1085 
   1086 void Logger::SetterCallbackEvent(Name* name, Address entry_point) {
   1087   CallbackEventInternal("set ", name, entry_point);
   1088 }
   1089 
   1090 static void AppendCodeCreateHeader(Log::MessageBuilder* msg,
   1091                                    CodeEventListener::LogEventsAndTags tag,
   1092                                    AbstractCode* code) {
   1093   DCHECK(msg);
   1094   msg->Append("%s,%s,%d,",
   1095               kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT],
   1096               kLogEventsNames[tag], code->kind());
   1097   msg->AppendAddress(code->address());
   1098   msg->Append(",%d,", code->ExecutableSize());
   1099 }
   1100 
   1101 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
   1102                              AbstractCode* code, const char* comment) {
   1103   if (!is_logging_code_events()) return;
   1104   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1105   Log::MessageBuilder msg(log_);
   1106   AppendCodeCreateHeader(&msg, tag, code);
   1107   msg.AppendDoubleQuotedString(comment);
   1108   msg.WriteToLogFile();
   1109 }
   1110 
   1111 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
   1112                              AbstractCode* code, Name* name) {
   1113   if (!is_logging_code_events()) return;
   1114   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1115   Log::MessageBuilder msg(log_);
   1116   AppendCodeCreateHeader(&msg, tag, code);
   1117   if (name->IsString()) {
   1118     msg.Append('"');
   1119     msg.AppendDetailed(String::cast(name), false);
   1120     msg.Append('"');
   1121   } else {
   1122     msg.AppendSymbolName(Symbol::cast(name));
   1123   }
   1124   msg.WriteToLogFile();
   1125 }
   1126 
   1127 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
   1128                              AbstractCode* code, SharedFunctionInfo* shared,
   1129                              Name* name) {
   1130   if (!is_logging_code_events()) return;
   1131   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1132   if (code == AbstractCode::cast(
   1133                   isolate_->builtins()->builtin(Builtins::kCompileLazy))) {
   1134     return;
   1135   }
   1136 
   1137   Log::MessageBuilder msg(log_);
   1138   AppendCodeCreateHeader(&msg, tag, code);
   1139   if (name->IsString()) {
   1140     base::SmartArrayPointer<char> str =
   1141         String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1142     msg.Append("\"%s\"", str.get());
   1143   } else {
   1144     msg.AppendSymbolName(Symbol::cast(name));
   1145   }
   1146   msg.Append(',');
   1147   msg.AppendAddress(shared->address());
   1148   msg.Append(",%s", ComputeMarker(shared, code));
   1149   msg.WriteToLogFile();
   1150 }
   1151 
   1152 
   1153 // Although, it is possible to extract source and line from
   1154 // the SharedFunctionInfo object, we left it to caller
   1155 // to leave logging functions free from heap allocations.
   1156 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
   1157                              AbstractCode* code, SharedFunctionInfo* shared,
   1158                              Name* source, int line, int column) {
   1159   if (!is_logging_code_events()) return;
   1160   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1161   Log::MessageBuilder msg(log_);
   1162   AppendCodeCreateHeader(&msg, tag, code);
   1163   base::SmartArrayPointer<char> name =
   1164       shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1165   msg.Append("\"%s ", name.get());
   1166   if (source->IsString()) {
   1167     base::SmartArrayPointer<char> sourcestr = String::cast(source)->ToCString(
   1168         DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1169     msg.Append("%s", sourcestr.get());
   1170   } else {
   1171     msg.AppendSymbolName(Symbol::cast(source));
   1172   }
   1173   msg.Append(":%d:%d\",", line, column);
   1174   msg.AppendAddress(shared->address());
   1175   msg.Append(",%s", ComputeMarker(shared, code));
   1176   msg.WriteToLogFile();
   1177 }
   1178 
   1179 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
   1180                              AbstractCode* code, int args_count) {
   1181   if (!is_logging_code_events()) return;
   1182   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1183   Log::MessageBuilder msg(log_);
   1184   AppendCodeCreateHeader(&msg, tag, code);
   1185   msg.Append("\"args_count: %d\"", args_count);
   1186   msg.WriteToLogFile();
   1187 }
   1188 
   1189 void Logger::CodeDisableOptEvent(AbstractCode* code,
   1190                                  SharedFunctionInfo* shared) {
   1191   if (!is_logging_code_events()) return;
   1192   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1193   Log::MessageBuilder msg(log_);
   1194   msg.Append("%s,", kLogEventsNames[CodeEventListener::CODE_DISABLE_OPT_EVENT]);
   1195   base::SmartArrayPointer<char> name =
   1196       shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1197   msg.Append("\"%s\",", name.get());
   1198   msg.Append("\"%s\"", GetBailoutReason(shared->disable_optimization_reason()));
   1199   msg.WriteToLogFile();
   1200 }
   1201 
   1202 
   1203 void Logger::CodeMovingGCEvent() {
   1204   if (!is_logging_code_events()) return;
   1205   if (!log_->IsEnabled() || !FLAG_ll_prof) return;
   1206   base::OS::SignalCodeMovingGC();
   1207 }
   1208 
   1209 void Logger::RegExpCodeCreateEvent(AbstractCode* code, String* source) {
   1210   if (!is_logging_code_events()) return;
   1211   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1212   Log::MessageBuilder msg(log_);
   1213   AppendCodeCreateHeader(&msg, CodeEventListener::REG_EXP_TAG, code);
   1214   msg.Append('"');
   1215   msg.AppendDetailed(source, false);
   1216   msg.Append('"');
   1217   msg.WriteToLogFile();
   1218 }
   1219 
   1220 void Logger::CodeMoveEvent(AbstractCode* from, Address to) {
   1221   if (!is_logging_code_events()) return;
   1222   MoveEventInternal(CodeEventListener::CODE_MOVE_EVENT, from->address(), to);
   1223 }
   1224 
   1225 void Logger::CodeLinePosInfoAddPositionEvent(void* jit_handler_data,
   1226                                              int pc_offset, int position) {
   1227   JIT_LOG(AddCodeLinePosInfoEvent(jit_handler_data,
   1228                                   pc_offset,
   1229                                   position,
   1230                                   JitCodeEvent::POSITION));
   1231 }
   1232 
   1233 
   1234 void Logger::CodeLinePosInfoAddStatementPositionEvent(void* jit_handler_data,
   1235                                                       int pc_offset,
   1236                                                       int position) {
   1237   JIT_LOG(AddCodeLinePosInfoEvent(jit_handler_data,
   1238                                   pc_offset,
   1239                                   position,
   1240                                   JitCodeEvent::STATEMENT_POSITION));
   1241 }
   1242 
   1243 
   1244 void Logger::CodeStartLinePosInfoRecordEvent(PositionsRecorder* pos_recorder) {
   1245   if (jit_logger_ != NULL) {
   1246       pos_recorder->AttachJITHandlerData(jit_logger_->StartCodePosInfoEvent());
   1247   }
   1248 }
   1249 
   1250 void Logger::CodeEndLinePosInfoRecordEvent(AbstractCode* code,
   1251                                            void* jit_handler_data) {
   1252   JIT_LOG(EndCodePosInfoEvent(code, jit_handler_data));
   1253 }
   1254 
   1255 
   1256 void Logger::CodeNameEvent(Address addr, int pos, const char* code_name) {
   1257   if (code_name == NULL) return;  // Not a code object.
   1258   Log::MessageBuilder msg(log_);
   1259   msg.Append("%s,%d,",
   1260              kLogEventsNames[CodeEventListener::SNAPSHOT_CODE_NAME_EVENT], pos);
   1261   msg.AppendDoubleQuotedString(code_name);
   1262   msg.WriteToLogFile();
   1263 }
   1264 
   1265 
   1266 void Logger::SharedFunctionInfoMoveEvent(Address from, Address to) {
   1267   if (!is_logging_code_events()) return;
   1268   MoveEventInternal(CodeEventListener::SHARED_FUNC_MOVE_EVENT, from, to);
   1269 }
   1270 
   1271 void Logger::MoveEventInternal(CodeEventListener::LogEventsAndTags event,
   1272                                Address from, Address to) {
   1273   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1274   Log::MessageBuilder msg(log_);
   1275   msg.Append("%s,", kLogEventsNames[event]);
   1276   msg.AppendAddress(from);
   1277   msg.Append(',');
   1278   msg.AppendAddress(to);
   1279   msg.WriteToLogFile();
   1280 }
   1281 
   1282 
   1283 void Logger::ResourceEvent(const char* name, const char* tag) {
   1284   if (!log_->IsEnabled() || !FLAG_log) return;
   1285   Log::MessageBuilder msg(log_);
   1286   msg.Append("%s,%s,", name, tag);
   1287 
   1288   uint32_t sec, usec;
   1289   if (base::OS::GetUserTime(&sec, &usec) != -1) {
   1290     msg.Append("%d,%d,", sec, usec);
   1291   }
   1292   msg.Append("%.0f", base::OS::TimeCurrentMillis());
   1293   msg.WriteToLogFile();
   1294 }
   1295 
   1296 
   1297 void Logger::SuspectReadEvent(Name* name, Object* obj) {
   1298   if (!log_->IsEnabled() || !FLAG_log_suspect) return;
   1299   Log::MessageBuilder msg(log_);
   1300   String* class_name = obj->IsJSObject()
   1301                        ? JSObject::cast(obj)->class_name()
   1302                        : isolate_->heap()->empty_string();
   1303   msg.Append("suspect-read,");
   1304   msg.Append(class_name);
   1305   msg.Append(',');
   1306   if (name->IsString()) {
   1307     msg.Append('"');
   1308     msg.Append(String::cast(name));
   1309     msg.Append('"');
   1310   } else {
   1311     msg.AppendSymbolName(Symbol::cast(name));
   1312   }
   1313   msg.WriteToLogFile();
   1314 }
   1315 
   1316 
   1317 void Logger::HeapSampleBeginEvent(const char* space, const char* kind) {
   1318   if (!log_->IsEnabled() || !FLAG_log_gc) return;
   1319   Log::MessageBuilder msg(log_);
   1320   // Using non-relative system time in order to be able to synchronize with
   1321   // external memory profiling events (e.g. DOM memory size).
   1322   msg.Append("heap-sample-begin,\"%s\",\"%s\",%.0f", space, kind,
   1323              base::OS::TimeCurrentMillis());
   1324   msg.WriteToLogFile();
   1325 }
   1326 
   1327 
   1328 void Logger::HeapSampleEndEvent(const char* space, const char* kind) {
   1329   if (!log_->IsEnabled() || !FLAG_log_gc) return;
   1330   Log::MessageBuilder msg(log_);
   1331   msg.Append("heap-sample-end,\"%s\",\"%s\"", space, kind);
   1332   msg.WriteToLogFile();
   1333 }
   1334 
   1335 
   1336 void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) {
   1337   if (!log_->IsEnabled() || !FLAG_log_gc) return;
   1338   Log::MessageBuilder msg(log_);
   1339   msg.Append("heap-sample-item,%s,%d,%d", type, number, bytes);
   1340   msg.WriteToLogFile();
   1341 }
   1342 
   1343 
   1344 void Logger::DebugTag(const char* call_site_tag) {
   1345   if (!log_->IsEnabled() || !FLAG_log) return;
   1346   Log::MessageBuilder msg(log_);
   1347   msg.Append("debug-tag,%s", call_site_tag);
   1348   msg.WriteToLogFile();
   1349 }
   1350 
   1351 
   1352 void Logger::DebugEvent(const char* event_type, Vector<uint16_t> parameter) {
   1353   if (!log_->IsEnabled() || !FLAG_log) return;
   1354   StringBuilder s(parameter.length() + 1);
   1355   for (int i = 0; i < parameter.length(); ++i) {
   1356     s.AddCharacter(static_cast<char>(parameter[i]));
   1357   }
   1358   char* parameter_string = s.Finalize();
   1359   Log::MessageBuilder msg(log_);
   1360   msg.Append("debug-queue-event,%s,%15.3f,%s", event_type,
   1361              base::OS::TimeCurrentMillis(), parameter_string);
   1362   DeleteArray(parameter_string);
   1363   msg.WriteToLogFile();
   1364 }
   1365 
   1366 void Logger::RuntimeCallTimerEvent() {
   1367   RuntimeCallStats* stats = isolate_->counters()->runtime_call_stats();
   1368   RuntimeCallTimer* timer = stats->current_timer();
   1369   if (timer == nullptr) return;
   1370   RuntimeCallCounter* counter = timer->counter();
   1371   if (counter == nullptr) return;
   1372   Log::MessageBuilder msg(log_);
   1373   msg.Append("active-runtime-timer,");
   1374   msg.AppendDoubleQuotedString(counter->name);
   1375   msg.WriteToLogFile();
   1376 }
   1377 
   1378 void Logger::TickEvent(TickSample* sample, bool overflow) {
   1379   if (!log_->IsEnabled() || !FLAG_prof_cpp) return;
   1380   if (FLAG_runtime_call_stats) {
   1381     RuntimeCallTimerEvent();
   1382   }
   1383   Log::MessageBuilder msg(log_);
   1384   msg.Append("%s,", kLogEventsNames[CodeEventListener::TICK_EVENT]);
   1385   msg.AppendAddress(sample->pc);
   1386   msg.Append(",%d", static_cast<int>(timer_.Elapsed().InMicroseconds()));
   1387   if (sample->has_external_callback) {
   1388     msg.Append(",1,");
   1389     msg.AppendAddress(sample->external_callback_entry);
   1390   } else {
   1391     msg.Append(",0,");
   1392     msg.AppendAddress(sample->tos);
   1393   }
   1394   msg.Append(",%d", static_cast<int>(sample->state));
   1395   if (overflow) {
   1396     msg.Append(",overflow");
   1397   }
   1398   for (unsigned i = 0; i < sample->frames_count; ++i) {
   1399     msg.Append(',');
   1400     msg.AppendAddress(sample->stack[i]);
   1401   }
   1402   msg.WriteToLogFile();
   1403 }
   1404 
   1405 
   1406 void Logger::StopProfiler() {
   1407   if (!log_->IsEnabled()) return;
   1408   if (profiler_ != NULL) {
   1409     profiler_->pause();
   1410     is_logging_ = false;
   1411     removeCodeEventListener(this);
   1412   }
   1413 }
   1414 
   1415 
   1416 // This function can be called when Log's mutex is acquired,
   1417 // either from main or Profiler's thread.
   1418 void Logger::LogFailure() {
   1419   StopProfiler();
   1420 }
   1421 
   1422 
   1423 class EnumerateOptimizedFunctionsVisitor: public OptimizedFunctionVisitor {
   1424  public:
   1425   EnumerateOptimizedFunctionsVisitor(Handle<SharedFunctionInfo>* sfis,
   1426                                      Handle<AbstractCode>* code_objects,
   1427                                      int* count)
   1428       : sfis_(sfis), code_objects_(code_objects), count_(count) {}
   1429 
   1430   virtual void EnterContext(Context* context) {}
   1431   virtual void LeaveContext(Context* context) {}
   1432 
   1433   virtual void VisitFunction(JSFunction* function) {
   1434     SharedFunctionInfo* sfi = SharedFunctionInfo::cast(function->shared());
   1435     Object* maybe_script = sfi->script();
   1436     if (maybe_script->IsScript()
   1437         && !Script::cast(maybe_script)->HasValidSource()) return;
   1438     if (sfis_ != NULL) {
   1439       sfis_[*count_] = Handle<SharedFunctionInfo>(sfi);
   1440     }
   1441     if (code_objects_ != NULL) {
   1442       DCHECK(function->abstract_code()->kind() ==
   1443              AbstractCode::OPTIMIZED_FUNCTION);
   1444       code_objects_[*count_] = Handle<AbstractCode>(function->abstract_code());
   1445     }
   1446     *count_ = *count_ + 1;
   1447   }
   1448 
   1449  private:
   1450   Handle<SharedFunctionInfo>* sfis_;
   1451   Handle<AbstractCode>* code_objects_;
   1452   int* count_;
   1453 };
   1454 
   1455 static int EnumerateCompiledFunctions(Heap* heap,
   1456                                       Handle<SharedFunctionInfo>* sfis,
   1457                                       Handle<AbstractCode>* code_objects) {
   1458   HeapIterator iterator(heap);
   1459   DisallowHeapAllocation no_gc;
   1460   int compiled_funcs_count = 0;
   1461 
   1462   // Iterate the heap to find shared function info objects and record
   1463   // the unoptimized code for them.
   1464   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
   1465     if (!obj->IsSharedFunctionInfo()) continue;
   1466     SharedFunctionInfo* sfi = SharedFunctionInfo::cast(obj);
   1467     if (sfi->is_compiled()
   1468         && (!sfi->script()->IsScript()
   1469             || Script::cast(sfi->script())->HasValidSource())) {
   1470       if (sfis != NULL) {
   1471         sfis[compiled_funcs_count] = Handle<SharedFunctionInfo>(sfi);
   1472       }
   1473       if (code_objects != NULL) {
   1474         code_objects[compiled_funcs_count] =
   1475             Handle<AbstractCode>(sfi->abstract_code());
   1476       }
   1477       ++compiled_funcs_count;
   1478     }
   1479   }
   1480 
   1481   // Iterate all optimized functions in all contexts.
   1482   EnumerateOptimizedFunctionsVisitor visitor(sfis,
   1483                                              code_objects,
   1484                                              &compiled_funcs_count);
   1485   Deoptimizer::VisitAllOptimizedFunctions(heap->isolate(), &visitor);
   1486 
   1487   return compiled_funcs_count;
   1488 }
   1489 
   1490 
   1491 void Logger::LogCodeObject(Object* object) {
   1492   AbstractCode* code_object = AbstractCode::cast(object);
   1493   CodeEventListener::LogEventsAndTags tag = CodeEventListener::STUB_TAG;
   1494   const char* description = "Unknown code from the snapshot";
   1495   switch (code_object->kind()) {
   1496     case AbstractCode::FUNCTION:
   1497     case AbstractCode::INTERPRETED_FUNCTION:
   1498     case AbstractCode::OPTIMIZED_FUNCTION:
   1499       return;  // We log this later using LogCompiledFunctions.
   1500     case AbstractCode::BYTECODE_HANDLER:
   1501       return;  // We log it later by walking the dispatch table.
   1502     case AbstractCode::BINARY_OP_IC:    // fall through
   1503     case AbstractCode::COMPARE_IC:      // fall through
   1504     case AbstractCode::TO_BOOLEAN_IC:   // fall through
   1505 
   1506     case AbstractCode::STUB:
   1507       description =
   1508           CodeStub::MajorName(CodeStub::GetMajorKey(code_object->GetCode()));
   1509       if (description == NULL)
   1510         description = "A stub from the snapshot";
   1511       tag = CodeEventListener::STUB_TAG;
   1512       break;
   1513     case AbstractCode::REGEXP:
   1514       description = "Regular expression code";
   1515       tag = CodeEventListener::REG_EXP_TAG;
   1516       break;
   1517     case AbstractCode::BUILTIN:
   1518       description =
   1519           isolate_->builtins()->name(code_object->GetCode()->builtin_index());
   1520       tag = CodeEventListener::BUILTIN_TAG;
   1521       break;
   1522     case AbstractCode::HANDLER:
   1523       description = "An IC handler from the snapshot";
   1524       tag = CodeEventListener::HANDLER_TAG;
   1525       break;
   1526     case AbstractCode::KEYED_LOAD_IC:
   1527       description = "A keyed load IC from the snapshot";
   1528       tag = CodeEventListener::KEYED_LOAD_IC_TAG;
   1529       break;
   1530     case AbstractCode::LOAD_IC:
   1531       description = "A load IC from the snapshot";
   1532       tag = CodeEventListener::LOAD_IC_TAG;
   1533       break;
   1534     case AbstractCode::LOAD_GLOBAL_IC:
   1535       description = "A load global IC from the snapshot";
   1536       tag = Logger::LOAD_GLOBAL_IC_TAG;
   1537       break;
   1538     case AbstractCode::CALL_IC:
   1539       description = "A call IC from the snapshot";
   1540       tag = CodeEventListener::CALL_IC_TAG;
   1541       break;
   1542     case AbstractCode::STORE_IC:
   1543       description = "A store IC from the snapshot";
   1544       tag = CodeEventListener::STORE_IC_TAG;
   1545       break;
   1546     case AbstractCode::KEYED_STORE_IC:
   1547       description = "A keyed store IC from the snapshot";
   1548       tag = CodeEventListener::KEYED_STORE_IC_TAG;
   1549       break;
   1550     case AbstractCode::WASM_FUNCTION:
   1551       description = "A Wasm function";
   1552       tag = CodeEventListener::STUB_TAG;
   1553       break;
   1554     case AbstractCode::JS_TO_WASM_FUNCTION:
   1555       description = "A JavaScript to Wasm adapter";
   1556       tag = CodeEventListener::STUB_TAG;
   1557       break;
   1558     case AbstractCode::WASM_TO_JS_FUNCTION:
   1559       description = "A Wasm to JavaScript adapter";
   1560       tag = CodeEventListener::STUB_TAG;
   1561       break;
   1562     case AbstractCode::NUMBER_OF_KINDS:
   1563       UNIMPLEMENTED();
   1564   }
   1565   PROFILE(isolate_, CodeCreateEvent(tag, code_object, description));
   1566 }
   1567 
   1568 
   1569 void Logger::LogCodeObjects() {
   1570   Heap* heap = isolate_->heap();
   1571   heap->CollectAllGarbage(Heap::kMakeHeapIterableMask,
   1572                           "Logger::LogCodeObjects");
   1573   HeapIterator iterator(heap);
   1574   DisallowHeapAllocation no_gc;
   1575   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
   1576     if (obj->IsCode()) LogCodeObject(obj);
   1577     if (obj->IsBytecodeArray()) LogCodeObject(obj);
   1578   }
   1579 }
   1580 
   1581 void Logger::LogBytecodeHandlers() {
   1582   if (!FLAG_ignition) return;
   1583 
   1584   const interpreter::OperandScale kOperandScales[] = {
   1585 #define VALUE(Name, _) interpreter::OperandScale::k##Name,
   1586       OPERAND_SCALE_LIST(VALUE)
   1587 #undef VALUE
   1588   };
   1589 
   1590   const int last_index = static_cast<int>(interpreter::Bytecode::kLast);
   1591   interpreter::Interpreter* interpreter = isolate_->interpreter();
   1592   for (auto operand_scale : kOperandScales) {
   1593     for (int index = 0; index <= last_index; ++index) {
   1594       interpreter::Bytecode bytecode = interpreter::Bytecodes::FromByte(index);
   1595       if (interpreter::Bytecodes::BytecodeHasHandler(bytecode, operand_scale)) {
   1596         Code* code = interpreter->GetBytecodeHandler(bytecode, operand_scale);
   1597         std::string bytecode_name =
   1598             interpreter::Bytecodes::ToString(bytecode, operand_scale);
   1599         PROFILE(isolate_, CodeCreateEvent(
   1600                               CodeEventListener::BYTECODE_HANDLER_TAG,
   1601                               AbstractCode::cast(code), bytecode_name.c_str()));
   1602       }
   1603     }
   1604   }
   1605 }
   1606 
   1607 void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared,
   1608                                  Handle<AbstractCode> code) {
   1609   Handle<String> func_name(shared->DebugName());
   1610   if (shared->script()->IsScript()) {
   1611     Handle<Script> script(Script::cast(shared->script()));
   1612     int line_num = Script::GetLineNumber(script, shared->start_position()) + 1;
   1613     int column_num =
   1614         Script::GetColumnNumber(script, shared->start_position()) + 1;
   1615     if (script->name()->IsString()) {
   1616       Handle<String> script_name(String::cast(script->name()));
   1617       if (line_num > 0) {
   1618         PROFILE(isolate_,
   1619                 CodeCreateEvent(
   1620                     Logger::ToNativeByScript(
   1621                         CodeEventListener::LAZY_COMPILE_TAG, *script),
   1622                     *code, *shared, *script_name, line_num, column_num));
   1623       } else {
   1624         // Can't distinguish eval and script here, so always use Script.
   1625         PROFILE(isolate_,
   1626                 CodeCreateEvent(Logger::ToNativeByScript(
   1627                                     CodeEventListener::SCRIPT_TAG, *script),
   1628                                 *code, *shared, *script_name));
   1629       }
   1630     } else {
   1631       PROFILE(isolate_,
   1632               CodeCreateEvent(Logger::ToNativeByScript(
   1633                                   CodeEventListener::LAZY_COMPILE_TAG, *script),
   1634                               *code, *shared, isolate_->heap()->empty_string(),
   1635                               line_num, column_num));
   1636     }
   1637   } else if (shared->IsApiFunction()) {
   1638     // API function.
   1639     FunctionTemplateInfo* fun_data = shared->get_api_func_data();
   1640     Object* raw_call_data = fun_data->call_code();
   1641     if (!raw_call_data->IsUndefined(isolate_)) {
   1642       CallHandlerInfo* call_data = CallHandlerInfo::cast(raw_call_data);
   1643       Object* callback_obj = call_data->callback();
   1644       Address entry_point = v8::ToCData<Address>(callback_obj);
   1645 #if USES_FUNCTION_DESCRIPTORS
   1646       entry_point = *FUNCTION_ENTRYPOINT_ADDRESS(entry_point);
   1647 #endif
   1648       PROFILE(isolate_, CallbackEvent(*func_name, entry_point));
   1649     }
   1650   } else {
   1651     PROFILE(isolate_, CodeCreateEvent(CodeEventListener::LAZY_COMPILE_TAG,
   1652                                       *code, *shared, *func_name));
   1653   }
   1654 }
   1655 
   1656 
   1657 void Logger::LogCompiledFunctions() {
   1658   Heap* heap = isolate_->heap();
   1659   heap->CollectAllGarbage(Heap::kMakeHeapIterableMask,
   1660                           "Logger::LogCompiledFunctions");
   1661   HandleScope scope(isolate_);
   1662   const int compiled_funcs_count = EnumerateCompiledFunctions(heap, NULL, NULL);
   1663   ScopedVector< Handle<SharedFunctionInfo> > sfis(compiled_funcs_count);
   1664   ScopedVector<Handle<AbstractCode> > code_objects(compiled_funcs_count);
   1665   EnumerateCompiledFunctions(heap, sfis.start(), code_objects.start());
   1666 
   1667   // During iteration, there can be heap allocation due to
   1668   // GetScriptLineNumber call.
   1669   for (int i = 0; i < compiled_funcs_count; ++i) {
   1670     if (code_objects[i].is_identical_to(isolate_->builtins()->CompileLazy()))
   1671       continue;
   1672     LogExistingFunction(sfis[i], code_objects[i]);
   1673   }
   1674 }
   1675 
   1676 
   1677 void Logger::LogAccessorCallbacks() {
   1678   Heap* heap = isolate_->heap();
   1679   heap->CollectAllGarbage(Heap::kMakeHeapIterableMask,
   1680                           "Logger::LogAccessorCallbacks");
   1681   HeapIterator iterator(heap);
   1682   DisallowHeapAllocation no_gc;
   1683   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
   1684     if (!obj->IsAccessorInfo()) continue;
   1685     AccessorInfo* ai = AccessorInfo::cast(obj);
   1686     if (!ai->name()->IsName()) continue;
   1687     Address getter_entry = v8::ToCData<Address>(ai->getter());
   1688     Name* name = Name::cast(ai->name());
   1689     if (getter_entry != 0) {
   1690 #if USES_FUNCTION_DESCRIPTORS
   1691       getter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(getter_entry);
   1692 #endif
   1693       PROFILE(isolate_, GetterCallbackEvent(name, getter_entry));
   1694     }
   1695     Address setter_entry = v8::ToCData<Address>(ai->setter());
   1696     if (setter_entry != 0) {
   1697 #if USES_FUNCTION_DESCRIPTORS
   1698       setter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(setter_entry);
   1699 #endif
   1700       PROFILE(isolate_, SetterCallbackEvent(name, setter_entry));
   1701     }
   1702   }
   1703 }
   1704 
   1705 
   1706 static void AddIsolateIdIfNeeded(std::ostream& os,  // NOLINT
   1707                                  Isolate* isolate) {
   1708   if (FLAG_logfile_per_isolate) os << "isolate-" << isolate << "-";
   1709 }
   1710 
   1711 
   1712 static void PrepareLogFileName(std::ostream& os,  // NOLINT
   1713                                Isolate* isolate, const char* file_name) {
   1714   int dir_separator_count = 0;
   1715   for (const char* p = file_name; *p; p++) {
   1716     if (base::OS::isDirectorySeparator(*p)) dir_separator_count++;
   1717   }
   1718 
   1719   for (const char* p = file_name; *p; p++) {
   1720     if (dir_separator_count == 0) {
   1721       AddIsolateIdIfNeeded(os, isolate);
   1722       dir_separator_count--;
   1723     }
   1724     if (*p == '%') {
   1725       p++;
   1726       switch (*p) {
   1727         case '\0':
   1728           // If there's a % at the end of the string we back up
   1729           // one character so we can escape the loop properly.
   1730           p--;
   1731           break;
   1732         case 'p':
   1733           os << base::OS::GetCurrentProcessId();
   1734           break;
   1735         case 't':
   1736           // %t expands to the current time in milliseconds.
   1737           os << static_cast<int64_t>(base::OS::TimeCurrentMillis());
   1738           break;
   1739         case '%':
   1740           // %% expands (contracts really) to %.
   1741           os << '%';
   1742           break;
   1743         default:
   1744           // All other %'s expand to themselves.
   1745           os << '%' << *p;
   1746           break;
   1747       }
   1748     } else {
   1749       if (base::OS::isDirectorySeparator(*p)) dir_separator_count--;
   1750       os << *p;
   1751     }
   1752   }
   1753 }
   1754 
   1755 
   1756 bool Logger::SetUp(Isolate* isolate) {
   1757   // Tests and EnsureInitialize() can call this twice in a row. It's harmless.
   1758   if (is_initialized_) return true;
   1759   is_initialized_ = true;
   1760 
   1761   std::ostringstream log_file_name;
   1762   PrepareLogFileName(log_file_name, isolate, FLAG_logfile);
   1763   log_->Initialize(log_file_name.str().c_str());
   1764 
   1765   if (FLAG_perf_basic_prof) {
   1766     perf_basic_logger_ = new PerfBasicLogger();
   1767     addCodeEventListener(perf_basic_logger_);
   1768   }
   1769 
   1770   if (FLAG_perf_prof) {
   1771     perf_jit_logger_ = new PerfJitLogger();
   1772     addCodeEventListener(perf_jit_logger_);
   1773   }
   1774 
   1775   if (FLAG_ll_prof) {
   1776     ll_logger_ = new LowLevelLogger(log_file_name.str().c_str());
   1777     addCodeEventListener(ll_logger_);
   1778   }
   1779 
   1780   ticker_ = new Ticker(isolate, kSamplingIntervalMs);
   1781 
   1782   if (Log::InitLogAtStart()) {
   1783     is_logging_ = true;
   1784   }
   1785 
   1786   if (FLAG_log_internal_timer_events || FLAG_prof_cpp) timer_.Start();
   1787 
   1788   if (FLAG_prof_cpp) {
   1789     profiler_ = new Profiler(isolate);
   1790     is_logging_ = true;
   1791     profiler_->Engage();
   1792   }
   1793 
   1794   profiler_listener_.reset();
   1795 
   1796   if (is_logging_) {
   1797     addCodeEventListener(this);
   1798   }
   1799 
   1800   return true;
   1801 }
   1802 
   1803 
   1804 void Logger::SetCodeEventHandler(uint32_t options,
   1805                                  JitCodeEventHandler event_handler) {
   1806   if (jit_logger_) {
   1807       removeCodeEventListener(jit_logger_);
   1808       delete jit_logger_;
   1809       jit_logger_ = NULL;
   1810   }
   1811 
   1812   if (event_handler) {
   1813     jit_logger_ = new JitLogger(event_handler);
   1814     addCodeEventListener(jit_logger_);
   1815     if (options & kJitCodeEventEnumExisting) {
   1816       HandleScope scope(isolate_);
   1817       LogCodeObjects();
   1818       LogCompiledFunctions();
   1819     }
   1820   }
   1821 }
   1822 
   1823 void Logger::SetUpProfilerListener() {
   1824   if (!is_initialized_) return;
   1825   if (profiler_listener_.get() == nullptr) {
   1826     profiler_listener_.reset(new ProfilerListener(isolate_));
   1827   }
   1828   addCodeEventListener(profiler_listener_.get());
   1829 }
   1830 
   1831 void Logger::TearDownProfilerListener() {
   1832   if (profiler_listener_->HasObservers()) return;
   1833   removeCodeEventListener(profiler_listener_.get());
   1834 }
   1835 
   1836 sampler::Sampler* Logger::sampler() {
   1837   return ticker_;
   1838 }
   1839 
   1840 
   1841 FILE* Logger::TearDown() {
   1842   if (!is_initialized_) return NULL;
   1843   is_initialized_ = false;
   1844 
   1845   // Stop the profiler before closing the file.
   1846   if (profiler_ != NULL) {
   1847     profiler_->Disengage();
   1848     delete profiler_;
   1849     profiler_ = NULL;
   1850   }
   1851 
   1852   delete ticker_;
   1853   ticker_ = NULL;
   1854 
   1855   if (perf_basic_logger_) {
   1856     removeCodeEventListener(perf_basic_logger_);
   1857     delete perf_basic_logger_;
   1858     perf_basic_logger_ = NULL;
   1859   }
   1860 
   1861   if (perf_jit_logger_) {
   1862     removeCodeEventListener(perf_jit_logger_);
   1863     delete perf_jit_logger_;
   1864     perf_jit_logger_ = NULL;
   1865   }
   1866 
   1867   if (ll_logger_) {
   1868     removeCodeEventListener(ll_logger_);
   1869     delete ll_logger_;
   1870     ll_logger_ = NULL;
   1871   }
   1872 
   1873   if (jit_logger_) {
   1874     removeCodeEventListener(jit_logger_);
   1875     delete jit_logger_;
   1876     jit_logger_ = NULL;
   1877   }
   1878 
   1879   if (profiler_listener_.get() != nullptr) {
   1880     removeCodeEventListener(profiler_listener_.get());
   1881   }
   1882 
   1883   return log_->Close();
   1884 }
   1885 
   1886 }  // namespace internal
   1887 }  // namespace v8
   1888