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