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