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, int column) {
    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 // Linux perf tool logging support
    250 class PerfBasicLogger : public CodeEventLogger {
    251  public:
    252   PerfBasicLogger();
    253   virtual ~PerfBasicLogger();
    254 
    255   virtual void CodeMoveEvent(Address from, Address to) { }
    256   virtual void CodeDeleteEvent(Address from) { }
    257 
    258  private:
    259   virtual void LogRecordedBuffer(Code* code,
    260                                  SharedFunctionInfo* shared,
    261                                  const char* name,
    262                                  int length);
    263 
    264   // Extension added to V8 log file name to get the low-level log name.
    265   static const char kFilenameFormatString[];
    266   static const int kFilenameBufferPadding;
    267 
    268   // File buffer size of the low-level log. We don't use the default to
    269   // minimize the associated overhead.
    270   static const int kLogBufferSize = 2 * MB;
    271 
    272   FILE* perf_output_handle_;
    273 };
    274 
    275 const char PerfBasicLogger::kFilenameFormatString[] = "/tmp/perf-%d.map";
    276 // Extra space for the PID in the filename
    277 const int PerfBasicLogger::kFilenameBufferPadding = 16;
    278 
    279 PerfBasicLogger::PerfBasicLogger()
    280     : perf_output_handle_(NULL) {
    281   // Open the perf JIT dump file.
    282   int bufferSize = sizeof(kFilenameFormatString) + kFilenameBufferPadding;
    283   ScopedVector<char> perf_dump_name(bufferSize);
    284   int size = OS::SNPrintF(
    285       perf_dump_name,
    286       kFilenameFormatString,
    287       OS::GetCurrentProcessId());
    288   CHECK_NE(size, -1);
    289   perf_output_handle_ = OS::FOpen(perf_dump_name.start(), OS::LogFileOpenMode);
    290   CHECK_NE(perf_output_handle_, NULL);
    291   setvbuf(perf_output_handle_, NULL, _IOFBF, kLogBufferSize);
    292 }
    293 
    294 
    295 PerfBasicLogger::~PerfBasicLogger() {
    296   fclose(perf_output_handle_);
    297   perf_output_handle_ = NULL;
    298 }
    299 
    300 
    301 void PerfBasicLogger::LogRecordedBuffer(Code* code,
    302                                        SharedFunctionInfo*,
    303                                        const char* name,
    304                                        int length) {
    305   ASSERT(code->instruction_start() == code->address() + Code::kHeaderSize);
    306 
    307   OS::FPrint(perf_output_handle_, "%llx %x %.*s\n",
    308       reinterpret_cast<uint64_t>(code->instruction_start()),
    309       code->instruction_size(),
    310       length, name);
    311 }
    312 
    313 
    314 // Linux perf tool logging support
    315 class PerfJitLogger : public CodeEventLogger {
    316  public:
    317   PerfJitLogger();
    318   virtual ~PerfJitLogger();
    319 
    320   virtual void CodeMoveEvent(Address from, Address to) { }
    321   virtual void CodeDeleteEvent(Address from) { }
    322 
    323  private:
    324   virtual void LogRecordedBuffer(Code* code,
    325                                  SharedFunctionInfo* shared,
    326                                  const char* name,
    327                                  int length);
    328 
    329   // Extension added to V8 log file name to get the low-level log name.
    330   static const char kFilenameFormatString[];
    331   static const int kFilenameBufferPadding;
    332 
    333   // File buffer size of the low-level log. We don't use the default to
    334   // minimize the associated overhead.
    335   static const int kLogBufferSize = 2 * MB;
    336 
    337   void LogWriteBytes(const char* bytes, int size);
    338   void LogWriteHeader();
    339 
    340   static const uint32_t kJitHeaderMagic = 0x4F74496A;
    341   static const uint32_t kJitHeaderVersion = 0x2;
    342   static const uint32_t kElfMachIA32 = 3;
    343   static const uint32_t kElfMachX64 = 62;
    344   static const uint32_t kElfMachARM = 40;
    345   static const uint32_t kElfMachMIPS = 10;
    346 
    347   struct jitheader {
    348     uint32_t magic;
    349     uint32_t version;
    350     uint32_t total_size;
    351     uint32_t elf_mach;
    352     uint32_t pad1;
    353     uint32_t pid;
    354     uint64_t timestamp;
    355   };
    356 
    357   enum jit_record_type {
    358     JIT_CODE_LOAD = 0
    359     // JIT_CODE_UNLOAD = 1,
    360     // JIT_CODE_CLOSE = 2,
    361     // JIT_CODE_DEBUG_INFO = 3,
    362     // JIT_CODE_PAGE_MAP = 4,
    363     // JIT_CODE_MAX = 5
    364   };
    365 
    366   struct jr_code_load {
    367     uint32_t id;
    368     uint32_t total_size;
    369     uint64_t timestamp;
    370     uint64_t vma;
    371     uint64_t code_addr;
    372     uint32_t code_size;
    373     uint32_t align;
    374   };
    375 
    376   uint32_t GetElfMach() {
    377 #if V8_TARGET_ARCH_IA32
    378     return kElfMachIA32;
    379 #elif V8_TARGET_ARCH_X64
    380     return kElfMachX64;
    381 #elif V8_TARGET_ARCH_ARM
    382     return kElfMachARM;
    383 #elif V8_TARGET_ARCH_MIPS
    384     return kElfMachMIPS;
    385 #else
    386     UNIMPLEMENTED();
    387     return 0;
    388 #endif
    389   }
    390 
    391   FILE* perf_output_handle_;
    392 };
    393 
    394 const char PerfJitLogger::kFilenameFormatString[] = "/tmp/jit-%d.dump";
    395 
    396 // Extra padding for the PID in the filename
    397 const int PerfJitLogger::kFilenameBufferPadding = 16;
    398 
    399 PerfJitLogger::PerfJitLogger()
    400     : perf_output_handle_(NULL) {
    401   // Open the perf JIT dump file.
    402   int bufferSize = sizeof(kFilenameFormatString) + kFilenameBufferPadding;
    403   ScopedVector<char> perf_dump_name(bufferSize);
    404   int size = OS::SNPrintF(
    405       perf_dump_name,
    406       kFilenameFormatString,
    407       OS::GetCurrentProcessId());
    408   CHECK_NE(size, -1);
    409   perf_output_handle_ = OS::FOpen(perf_dump_name.start(), OS::LogFileOpenMode);
    410   CHECK_NE(perf_output_handle_, NULL);
    411   setvbuf(perf_output_handle_, NULL, _IOFBF, kLogBufferSize);
    412 
    413   LogWriteHeader();
    414 }
    415 
    416 
    417 PerfJitLogger::~PerfJitLogger() {
    418   fclose(perf_output_handle_);
    419   perf_output_handle_ = NULL;
    420 }
    421 
    422 
    423 void PerfJitLogger::LogRecordedBuffer(Code* code,
    424                                       SharedFunctionInfo*,
    425                                       const char* name,
    426                                       int length) {
    427   ASSERT(code->instruction_start() == code->address() + Code::kHeaderSize);
    428   ASSERT(perf_output_handle_ != NULL);
    429 
    430   const char* code_name = name;
    431   uint8_t* code_pointer = reinterpret_cast<uint8_t*>(code->instruction_start());
    432   uint32_t code_size = code->instruction_size();
    433 
    434   static const char string_terminator[] = "\0";
    435 
    436   jr_code_load code_load;
    437   code_load.id = JIT_CODE_LOAD;
    438   code_load.total_size = sizeof(code_load) + length + 1 + code_size;
    439   code_load.timestamp =
    440       static_cast<uint64_t>(OS::TimeCurrentMillis() * 1000.0);
    441   code_load.vma = 0x0;  //  Our addresses are absolute.
    442   code_load.code_addr = reinterpret_cast<uint64_t>(code->instruction_start());
    443   code_load.code_size = code_size;
    444   code_load.align = 0;
    445 
    446   LogWriteBytes(reinterpret_cast<const char*>(&code_load), sizeof(code_load));
    447   LogWriteBytes(code_name, length);
    448   LogWriteBytes(string_terminator, 1);
    449   LogWriteBytes(reinterpret_cast<const char*>(code_pointer), code_size);
    450 }
    451 
    452 
    453 void PerfJitLogger::LogWriteBytes(const char* bytes, int size) {
    454   size_t rv = fwrite(bytes, 1, size, perf_output_handle_);
    455   ASSERT(static_cast<size_t>(size) == rv);
    456   USE(rv);
    457 }
    458 
    459 
    460 void PerfJitLogger::LogWriteHeader() {
    461   ASSERT(perf_output_handle_ != NULL);
    462   jitheader header;
    463   header.magic = kJitHeaderMagic;
    464   header.version = kJitHeaderVersion;
    465   header.total_size = sizeof(jitheader);
    466   header.pad1 = 0xdeadbeef;
    467   header.elf_mach = GetElfMach();
    468   header.pid = OS::GetCurrentProcessId();
    469   header.timestamp = static_cast<uint64_t>(OS::TimeCurrentMillis() * 1000.0);
    470   LogWriteBytes(reinterpret_cast<const char*>(&header), sizeof(header));
    471 }
    472 
    473 
    474 // Low-level logging support.
    475 #define LL_LOG(Call) if (ll_logger_) ll_logger_->Call;
    476 
    477 class LowLevelLogger : public CodeEventLogger {
    478  public:
    479   explicit LowLevelLogger(const char* file_name);
    480   virtual ~LowLevelLogger();
    481 
    482   virtual void CodeMoveEvent(Address from, Address to);
    483   virtual void CodeDeleteEvent(Address from);
    484   virtual void SnapshotPositionEvent(Address addr, int pos);
    485   virtual void CodeMovingGCEvent();
    486 
    487  private:
    488   virtual void LogRecordedBuffer(Code* code,
    489                                  SharedFunctionInfo* shared,
    490                                  const char* name,
    491                                  int length);
    492 
    493   // Low-level profiling event structures.
    494   struct CodeCreateStruct {
    495     static const char kTag = 'C';
    496 
    497     int32_t name_size;
    498     Address code_address;
    499     int32_t code_size;
    500   };
    501 
    502 
    503   struct CodeMoveStruct {
    504     static const char kTag = 'M';
    505 
    506     Address from_address;
    507     Address to_address;
    508   };
    509 
    510 
    511   struct CodeDeleteStruct {
    512     static const char kTag = 'D';
    513 
    514     Address address;
    515   };
    516 
    517 
    518   struct SnapshotPositionStruct {
    519     static const char kTag = 'P';
    520 
    521     Address address;
    522     int32_t position;
    523   };
    524 
    525 
    526   static const char kCodeMovingGCTag = 'G';
    527 
    528 
    529   // Extension added to V8 log file name to get the low-level log name.
    530   static const char kLogExt[];
    531 
    532   // File buffer size of the low-level log. We don't use the default to
    533   // minimize the associated overhead.
    534   static const int kLogBufferSize = 2 * MB;
    535 
    536   void LogCodeInfo();
    537   void LogWriteBytes(const char* bytes, int size);
    538 
    539   template <typename T>
    540   void LogWriteStruct(const T& s) {
    541     char tag = T::kTag;
    542     LogWriteBytes(reinterpret_cast<const char*>(&tag), sizeof(tag));
    543     LogWriteBytes(reinterpret_cast<const char*>(&s), sizeof(s));
    544   }
    545 
    546   FILE* ll_output_handle_;
    547 };
    548 
    549 const char LowLevelLogger::kLogExt[] = ".ll";
    550 
    551 LowLevelLogger::LowLevelLogger(const char* name)
    552     : ll_output_handle_(NULL) {
    553   // Open the low-level log file.
    554   size_t len = strlen(name);
    555   ScopedVector<char> ll_name(static_cast<int>(len + sizeof(kLogExt)));
    556   OS::MemCopy(ll_name.start(), name, len);
    557   OS::MemCopy(ll_name.start() + len, kLogExt, sizeof(kLogExt));
    558   ll_output_handle_ = OS::FOpen(ll_name.start(), OS::LogFileOpenMode);
    559   setvbuf(ll_output_handle_, NULL, _IOFBF, kLogBufferSize);
    560 
    561   LogCodeInfo();
    562 }
    563 
    564 
    565 LowLevelLogger::~LowLevelLogger() {
    566   fclose(ll_output_handle_);
    567   ll_output_handle_ = NULL;
    568 }
    569 
    570 
    571 void LowLevelLogger::LogCodeInfo() {
    572 #if V8_TARGET_ARCH_IA32
    573   const char arch[] = "ia32";
    574 #elif V8_TARGET_ARCH_X64
    575   const char arch[] = "x64";
    576 #elif V8_TARGET_ARCH_ARM
    577   const char arch[] = "arm";
    578 #elif V8_TARGET_ARCH_MIPS
    579   const char arch[] = "mips";
    580 #else
    581   const char arch[] = "unknown";
    582 #endif
    583   LogWriteBytes(arch, sizeof(arch));
    584 }
    585 
    586 
    587 void LowLevelLogger::LogRecordedBuffer(Code* code,
    588                                        SharedFunctionInfo*,
    589                                        const char* name,
    590                                        int length) {
    591   CodeCreateStruct event;
    592   event.name_size = length;
    593   event.code_address = code->instruction_start();
    594   ASSERT(event.code_address == code->address() + Code::kHeaderSize);
    595   event.code_size = code->instruction_size();
    596   LogWriteStruct(event);
    597   LogWriteBytes(name, length);
    598   LogWriteBytes(
    599       reinterpret_cast<const char*>(code->instruction_start()),
    600       code->instruction_size());
    601 }
    602 
    603 
    604 void LowLevelLogger::CodeMoveEvent(Address from, Address to) {
    605   CodeMoveStruct event;
    606   event.from_address = from + Code::kHeaderSize;
    607   event.to_address = to + Code::kHeaderSize;
    608   LogWriteStruct(event);
    609 }
    610 
    611 
    612 void LowLevelLogger::CodeDeleteEvent(Address from) {
    613   CodeDeleteStruct event;
    614   event.address = from + Code::kHeaderSize;
    615   LogWriteStruct(event);
    616 }
    617 
    618 
    619 void LowLevelLogger::SnapshotPositionEvent(Address addr, int pos) {
    620   SnapshotPositionStruct event;
    621   event.address = addr + Code::kHeaderSize;
    622   event.position = pos;
    623   LogWriteStruct(event);
    624 }
    625 
    626 
    627 void LowLevelLogger::LogWriteBytes(const char* bytes, int size) {
    628   size_t rv = fwrite(bytes, 1, size, ll_output_handle_);
    629   ASSERT(static_cast<size_t>(size) == rv);
    630   USE(rv);
    631 }
    632 
    633 
    634 void LowLevelLogger::CodeMovingGCEvent() {
    635   const char tag = kCodeMovingGCTag;
    636 
    637   LogWriteBytes(&tag, sizeof(tag));
    638 }
    639 
    640 
    641 #define JIT_LOG(Call) if (jit_logger_) jit_logger_->Call;
    642 
    643 
    644 class JitLogger : public CodeEventLogger {
    645  public:
    646   explicit JitLogger(JitCodeEventHandler code_event_handler);
    647 
    648   virtual void CodeMoveEvent(Address from, Address to);
    649   virtual void CodeDeleteEvent(Address from);
    650   virtual void AddCodeLinePosInfoEvent(
    651       void* jit_handler_data,
    652       int pc_offset,
    653       int position,
    654       JitCodeEvent::PositionType position_type);
    655 
    656   void* StartCodePosInfoEvent();
    657   void EndCodePosInfoEvent(Code* code, void* jit_handler_data);
    658 
    659  private:
    660   virtual void LogRecordedBuffer(Code* code,
    661                                  SharedFunctionInfo* shared,
    662                                  const char* name,
    663                                  int length);
    664 
    665   JitCodeEventHandler code_event_handler_;
    666 };
    667 
    668 
    669 JitLogger::JitLogger(JitCodeEventHandler code_event_handler)
    670     : code_event_handler_(code_event_handler) {
    671 }
    672 
    673 
    674 void JitLogger::LogRecordedBuffer(Code* code,
    675                                   SharedFunctionInfo* shared,
    676                                   const char* name,
    677                                   int length) {
    678   JitCodeEvent event;
    679   memset(&event, 0, sizeof(event));
    680   event.type = JitCodeEvent::CODE_ADDED;
    681   event.code_start = code->instruction_start();
    682   event.code_len = code->instruction_size();
    683   Handle<Script> script_handle;
    684   if (shared && shared->script()->IsScript()) {
    685     script_handle = Handle<Script>(Script::cast(shared->script()));
    686   }
    687   event.script = ToApiHandle<v8::Script>(script_handle);
    688   event.name.str = name;
    689   event.name.len = length;
    690   code_event_handler_(&event);
    691 }
    692 
    693 
    694 void JitLogger::CodeMoveEvent(Address from, Address to) {
    695   Code* from_code = Code::cast(HeapObject::FromAddress(from));
    696 
    697   JitCodeEvent event;
    698   event.type = JitCodeEvent::CODE_MOVED;
    699   event.code_start = from_code->instruction_start();
    700   event.code_len = from_code->instruction_size();
    701 
    702   // Calculate the header size.
    703   const size_t header_size =
    704       from_code->instruction_start() - reinterpret_cast<byte*>(from_code);
    705 
    706   // Calculate the new start address of the instructions.
    707   event.new_code_start =
    708       reinterpret_cast<byte*>(HeapObject::FromAddress(to)) + header_size;
    709 
    710   code_event_handler_(&event);
    711 }
    712 
    713 
    714 void JitLogger::CodeDeleteEvent(Address from) {
    715   Code* from_code = Code::cast(HeapObject::FromAddress(from));
    716 
    717   JitCodeEvent event;
    718   event.type = JitCodeEvent::CODE_REMOVED;
    719   event.code_start = from_code->instruction_start();
    720   event.code_len = from_code->instruction_size();
    721 
    722   code_event_handler_(&event);
    723 }
    724 
    725 void JitLogger::AddCodeLinePosInfoEvent(
    726     void* jit_handler_data,
    727     int pc_offset,
    728     int position,
    729     JitCodeEvent::PositionType position_type) {
    730   JitCodeEvent event;
    731   memset(&event, 0, sizeof(event));
    732   event.type = JitCodeEvent::CODE_ADD_LINE_POS_INFO;
    733   event.user_data = jit_handler_data;
    734   event.line_info.offset = pc_offset;
    735   event.line_info.pos = position;
    736   event.line_info.position_type = position_type;
    737 
    738   code_event_handler_(&event);
    739 }
    740 
    741 
    742 void* JitLogger::StartCodePosInfoEvent() {
    743   JitCodeEvent event;
    744   memset(&event, 0, sizeof(event));
    745   event.type = JitCodeEvent::CODE_START_LINE_INFO_RECORDING;
    746 
    747   code_event_handler_(&event);
    748   return event.user_data;
    749 }
    750 
    751 
    752 void JitLogger::EndCodePosInfoEvent(Code* code, void* jit_handler_data) {
    753   JitCodeEvent event;
    754   memset(&event, 0, sizeof(event));
    755   event.type = JitCodeEvent::CODE_END_LINE_INFO_RECORDING;
    756   event.code_start = code->instruction_start();
    757   event.user_data = jit_handler_data;
    758 
    759   code_event_handler_(&event);
    760 }
    761 
    762 
    763 // The Profiler samples pc and sp values for the main thread.
    764 // Each sample is appended to a circular buffer.
    765 // An independent thread removes data and writes it to the log.
    766 // This design minimizes the time spent in the sampler.
    767 //
    768 class Profiler: public Thread {
    769  public:
    770   explicit Profiler(Isolate* isolate);
    771   void Engage();
    772   void Disengage();
    773 
    774   // Inserts collected profiling data into buffer.
    775   void Insert(TickSample* sample) {
    776     if (paused_)
    777       return;
    778 
    779     if (Succ(head_) == tail_) {
    780       overflow_ = true;
    781     } else {
    782       buffer_[head_] = *sample;
    783       head_ = Succ(head_);
    784       buffer_semaphore_.Signal();  // Tell we have an element.
    785     }
    786   }
    787 
    788   virtual void Run();
    789 
    790   // Pause and Resume TickSample data collection.
    791   void pause() { paused_ = true; }
    792   void resume() { paused_ = false; }
    793 
    794  private:
    795   // Waits for a signal and removes profiling data.
    796   bool Remove(TickSample* sample) {
    797     buffer_semaphore_.Wait();  // Wait for an element.
    798     *sample = buffer_[tail_];
    799     bool result = overflow_;
    800     tail_ = Succ(tail_);
    801     overflow_ = false;
    802     return result;
    803   }
    804 
    805   // Returns the next index in the cyclic buffer.
    806   int Succ(int index) { return (index + 1) % kBufferSize; }
    807 
    808   Isolate* isolate_;
    809   // Cyclic buffer for communicating profiling samples
    810   // between the signal handler and the worker thread.
    811   static const int kBufferSize = 128;
    812   TickSample buffer_[kBufferSize];  // Buffer storage.
    813   int head_;  // Index to the buffer head.
    814   int tail_;  // Index to the buffer tail.
    815   bool overflow_;  // Tell whether a buffer overflow has occurred.
    816   // Sempahore used for buffer synchronization.
    817   Semaphore buffer_semaphore_;
    818 
    819   // Tells whether profiler is engaged, that is, processing thread is stated.
    820   bool engaged_;
    821 
    822   // Tells whether worker thread should continue running.
    823   bool running_;
    824 
    825   // Tells whether we are currently recording tick samples.
    826   bool paused_;
    827 };
    828 
    829 
    830 //
    831 // Ticker used to provide ticks to the profiler and the sliding state
    832 // window.
    833 //
    834 class Ticker: public Sampler {
    835  public:
    836   Ticker(Isolate* isolate, int interval):
    837       Sampler(isolate, interval),
    838       profiler_(NULL) {}
    839 
    840   ~Ticker() { if (IsActive()) Stop(); }
    841 
    842   virtual void Tick(TickSample* sample) {
    843     if (profiler_) profiler_->Insert(sample);
    844   }
    845 
    846   void SetProfiler(Profiler* profiler) {
    847     ASSERT(profiler_ == NULL);
    848     profiler_ = profiler;
    849     IncreaseProfilingDepth();
    850     if (!IsActive()) Start();
    851   }
    852 
    853   void ClearProfiler() {
    854     profiler_ = NULL;
    855     if (IsActive()) Stop();
    856     DecreaseProfilingDepth();
    857   }
    858 
    859  private:
    860   Profiler* profiler_;
    861 };
    862 
    863 
    864 //
    865 // Profiler implementation.
    866 //
    867 Profiler::Profiler(Isolate* isolate)
    868     : Thread("v8:Profiler"),
    869       isolate_(isolate),
    870       head_(0),
    871       tail_(0),
    872       overflow_(false),
    873       buffer_semaphore_(0),
    874       engaged_(false),
    875       running_(false),
    876       paused_(false) {
    877 }
    878 
    879 
    880 void Profiler::Engage() {
    881   if (engaged_) return;
    882   engaged_ = true;
    883 
    884   OS::LogSharedLibraryAddresses(isolate_);
    885 
    886   // Start thread processing the profiler buffer.
    887   running_ = true;
    888   Start();
    889 
    890   // Register to get ticks.
    891   Logger* logger = isolate_->logger();
    892   logger->ticker_->SetProfiler(this);
    893 
    894   logger->ProfilerBeginEvent();
    895 }
    896 
    897 
    898 void Profiler::Disengage() {
    899   if (!engaged_) return;
    900 
    901   // Stop receiving ticks.
    902   isolate_->logger()->ticker_->ClearProfiler();
    903 
    904   // Terminate the worker thread by setting running_ to false,
    905   // inserting a fake element in the queue and then wait for
    906   // the thread to terminate.
    907   running_ = false;
    908   TickSample sample;
    909   // Reset 'paused_' flag, otherwise semaphore may not be signalled.
    910   resume();
    911   Insert(&sample);
    912   Join();
    913 
    914   LOG(isolate_, UncheckedStringEvent("profiler", "end"));
    915 }
    916 
    917 
    918 void Profiler::Run() {
    919   TickSample sample;
    920   bool overflow = Remove(&sample);
    921   while (running_) {
    922     LOG(isolate_, TickEvent(&sample, overflow));
    923     overflow = Remove(&sample);
    924   }
    925 }
    926 
    927 
    928 //
    929 // Logger class implementation.
    930 //
    931 
    932 Logger::Logger(Isolate* isolate)
    933   : isolate_(isolate),
    934     ticker_(NULL),
    935     profiler_(NULL),
    936     log_events_(NULL),
    937     is_logging_(false),
    938     log_(new Log(this)),
    939     perf_basic_logger_(NULL),
    940     perf_jit_logger_(NULL),
    941     ll_logger_(NULL),
    942     jit_logger_(NULL),
    943     listeners_(5),
    944     is_initialized_(false) {
    945 }
    946 
    947 
    948 Logger::~Logger() {
    949   delete log_;
    950 }
    951 
    952 
    953 void Logger::addCodeEventListener(CodeEventListener* listener) {
    954   ASSERT(!hasCodeEventListener(listener));
    955   listeners_.Add(listener);
    956 }
    957 
    958 
    959 void Logger::removeCodeEventListener(CodeEventListener* listener) {
    960   ASSERT(hasCodeEventListener(listener));
    961   listeners_.RemoveElement(listener);
    962 }
    963 
    964 
    965 bool Logger::hasCodeEventListener(CodeEventListener* listener) {
    966   return listeners_.Contains(listener);
    967 }
    968 
    969 
    970 void Logger::ProfilerBeginEvent() {
    971   if (!log_->IsEnabled()) return;
    972   Log::MessageBuilder msg(log_);
    973   msg.Append("profiler,\"begin\",%d\n", kSamplingIntervalMs);
    974   msg.WriteToLogFile();
    975 }
    976 
    977 
    978 void Logger::StringEvent(const char* name, const char* value) {
    979   if (FLAG_log) UncheckedStringEvent(name, value);
    980 }
    981 
    982 
    983 void Logger::UncheckedStringEvent(const char* name, const char* value) {
    984   if (!log_->IsEnabled()) return;
    985   Log::MessageBuilder msg(log_);
    986   msg.Append("%s,\"%s\"\n", name, value);
    987   msg.WriteToLogFile();
    988 }
    989 
    990 
    991 void Logger::IntEvent(const char* name, int value) {
    992   if (FLAG_log) UncheckedIntEvent(name, value);
    993 }
    994 
    995 
    996 void Logger::IntPtrTEvent(const char* name, intptr_t value) {
    997   if (FLAG_log) UncheckedIntPtrTEvent(name, value);
    998 }
    999 
   1000 
   1001 void Logger::UncheckedIntEvent(const char* name, int value) {
   1002   if (!log_->IsEnabled()) return;
   1003   Log::MessageBuilder msg(log_);
   1004   msg.Append("%s,%d\n", name, value);
   1005   msg.WriteToLogFile();
   1006 }
   1007 
   1008 
   1009 void Logger::UncheckedIntPtrTEvent(const char* name, intptr_t value) {
   1010   if (!log_->IsEnabled()) return;
   1011   Log::MessageBuilder msg(log_);
   1012   msg.Append("%s,%" V8_PTR_PREFIX "d\n", name, value);
   1013   msg.WriteToLogFile();
   1014 }
   1015 
   1016 
   1017 void Logger::HandleEvent(const char* name, Object** location) {
   1018   if (!log_->IsEnabled() || !FLAG_log_handles) return;
   1019   Log::MessageBuilder msg(log_);
   1020   msg.Append("%s,0x%" V8PRIxPTR "\n", name, location);
   1021   msg.WriteToLogFile();
   1022 }
   1023 
   1024 
   1025 // ApiEvent is private so all the calls come from the Logger class.  It is the
   1026 // caller's responsibility to ensure that log is enabled and that
   1027 // FLAG_log_api is true.
   1028 void Logger::ApiEvent(const char* format, ...) {
   1029   ASSERT(log_->IsEnabled() && FLAG_log_api);
   1030   Log::MessageBuilder msg(log_);
   1031   va_list ap;
   1032   va_start(ap, format);
   1033   msg.AppendVA(format, ap);
   1034   va_end(ap);
   1035   msg.WriteToLogFile();
   1036 }
   1037 
   1038 
   1039 void Logger::ApiNamedSecurityCheck(Object* key) {
   1040   if (!log_->IsEnabled() || !FLAG_log_api) return;
   1041   if (key->IsString()) {
   1042     SmartArrayPointer<char> str =
   1043         String::cast(key)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1044     ApiEvent("api,check-security,\"%s\"\n", *str);
   1045   } else if (key->IsSymbol()) {
   1046     Symbol* symbol = Symbol::cast(key);
   1047     if (symbol->name()->IsUndefined()) {
   1048       ApiEvent("api,check-security,symbol(hash %x)\n",
   1049                Symbol::cast(key)->Hash());
   1050     } else {
   1051       SmartArrayPointer<char> str = String::cast(symbol->name())->ToCString(
   1052           DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1053       ApiEvent("api,check-security,symbol(\"%s\" hash %x)\n",
   1054                *str,
   1055                Symbol::cast(key)->Hash());
   1056     }
   1057   } else if (key->IsUndefined()) {
   1058     ApiEvent("api,check-security,undefined\n");
   1059   } else {
   1060     ApiEvent("api,check-security,['no-name']\n");
   1061   }
   1062 }
   1063 
   1064 
   1065 void Logger::SharedLibraryEvent(const char* library_path,
   1066                                 uintptr_t start,
   1067                                 uintptr_t end) {
   1068   if (!log_->IsEnabled() || !FLAG_prof) return;
   1069   Log::MessageBuilder msg(log_);
   1070   msg.Append("shared-library,\"%s\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR "\n",
   1071              library_path,
   1072              start,
   1073              end);
   1074   msg.WriteToLogFile();
   1075 }
   1076 
   1077 
   1078 void Logger::SharedLibraryEvent(const wchar_t* library_path,
   1079                                 uintptr_t start,
   1080                                 uintptr_t end) {
   1081   if (!log_->IsEnabled() || !FLAG_prof) return;
   1082   Log::MessageBuilder msg(log_);
   1083   msg.Append("shared-library,\"%ls\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR "\n",
   1084              library_path,
   1085              start,
   1086              end);
   1087   msg.WriteToLogFile();
   1088 }
   1089 
   1090 
   1091 void Logger::CodeDeoptEvent(Code* code) {
   1092   if (!log_->IsEnabled()) return;
   1093   ASSERT(FLAG_log_internal_timer_events);
   1094   Log::MessageBuilder msg(log_);
   1095   int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());
   1096   msg.Append("code-deopt,%ld,%d\n", since_epoch, code->CodeSize());
   1097   msg.WriteToLogFile();
   1098 }
   1099 
   1100 
   1101 void Logger::TimerEvent(StartEnd se, const char* name) {
   1102   if (!log_->IsEnabled()) return;
   1103   ASSERT(FLAG_log_internal_timer_events);
   1104   Log::MessageBuilder msg(log_);
   1105   int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());
   1106   const char* format = (se == START) ? "timer-event-start,\"%s\",%ld\n"
   1107                                      : "timer-event-end,\"%s\",%ld\n";
   1108   msg.Append(format, name, since_epoch);
   1109   msg.WriteToLogFile();
   1110 }
   1111 
   1112 
   1113 void Logger::EnterExternal(Isolate* isolate) {
   1114   LOG(isolate, TimerEvent(START, TimerEventScope::v8_external));
   1115   ASSERT(isolate->current_vm_state() == JS);
   1116   isolate->set_current_vm_state(EXTERNAL);
   1117 }
   1118 
   1119 
   1120 void Logger::LeaveExternal(Isolate* isolate) {
   1121   LOG(isolate, TimerEvent(END, TimerEventScope::v8_external));
   1122   ASSERT(isolate->current_vm_state() == EXTERNAL);
   1123   isolate->set_current_vm_state(JS);
   1124 }
   1125 
   1126 
   1127 void Logger::TimerEventScope::LogTimerEvent(StartEnd se) {
   1128   LOG(isolate_, TimerEvent(se, name_));
   1129 }
   1130 
   1131 
   1132 const char* Logger::TimerEventScope::v8_recompile_synchronous =
   1133     "V8.RecompileSynchronous";
   1134 const char* Logger::TimerEventScope::v8_recompile_concurrent =
   1135     "V8.RecompileConcurrent";
   1136 const char* Logger::TimerEventScope::v8_compile_full_code =
   1137     "V8.CompileFullCode";
   1138 const char* Logger::TimerEventScope::v8_execute = "V8.Execute";
   1139 const char* Logger::TimerEventScope::v8_external = "V8.External";
   1140 
   1141 
   1142 void Logger::LogRegExpSource(Handle<JSRegExp> regexp) {
   1143   // Prints "/" + re.source + "/" +
   1144   //      (re.global?"g":"") + (re.ignorecase?"i":"") + (re.multiline?"m":"")
   1145   Log::MessageBuilder msg(log_);
   1146 
   1147   Handle<Object> source = GetProperty(regexp, "source");
   1148   if (!source->IsString()) {
   1149     msg.Append("no source");
   1150     return;
   1151   }
   1152 
   1153   switch (regexp->TypeTag()) {
   1154     case JSRegExp::ATOM:
   1155       msg.Append('a');
   1156       break;
   1157     default:
   1158       break;
   1159   }
   1160   msg.Append('/');
   1161   msg.AppendDetailed(*Handle<String>::cast(source), false);
   1162   msg.Append('/');
   1163 
   1164   // global flag
   1165   Handle<Object> global = GetProperty(regexp, "global");
   1166   if (global->IsTrue()) {
   1167     msg.Append('g');
   1168   }
   1169   // ignorecase flag
   1170   Handle<Object> ignorecase = GetProperty(regexp, "ignoreCase");
   1171   if (ignorecase->IsTrue()) {
   1172     msg.Append('i');
   1173   }
   1174   // multiline flag
   1175   Handle<Object> multiline = GetProperty(regexp, "multiline");
   1176   if (multiline->IsTrue()) {
   1177     msg.Append('m');
   1178   }
   1179 
   1180   msg.WriteToLogFile();
   1181 }
   1182 
   1183 
   1184 void Logger::RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache) {
   1185   if (!log_->IsEnabled() || !FLAG_log_regexp) return;
   1186   Log::MessageBuilder msg(log_);
   1187   msg.Append("regexp-compile,");
   1188   LogRegExpSource(regexp);
   1189   msg.Append(in_cache ? ",hit\n" : ",miss\n");
   1190   msg.WriteToLogFile();
   1191 }
   1192 
   1193 
   1194 void Logger::LogRuntime(Vector<const char> format,
   1195                         JSArray* args) {
   1196   if (!log_->IsEnabled() || !FLAG_log_runtime) return;
   1197   HandleScope scope(isolate_);
   1198   Log::MessageBuilder msg(log_);
   1199   for (int i = 0; i < format.length(); i++) {
   1200     char c = format[i];
   1201     if (c == '%' && i <= format.length() - 2) {
   1202       i++;
   1203       ASSERT('0' <= format[i] && format[i] <= '9');
   1204       MaybeObject* maybe = args->GetElement(isolate_, format[i] - '0');
   1205       Object* obj;
   1206       if (!maybe->ToObject(&obj)) {
   1207         msg.Append("<exception>");
   1208         continue;
   1209       }
   1210       i++;
   1211       switch (format[i]) {
   1212         case 's':
   1213           msg.AppendDetailed(String::cast(obj), false);
   1214           break;
   1215         case 'S':
   1216           msg.AppendDetailed(String::cast(obj), true);
   1217           break;
   1218         case 'r':
   1219           Logger::LogRegExpSource(Handle<JSRegExp>(JSRegExp::cast(obj)));
   1220           break;
   1221         case 'x':
   1222           msg.Append("0x%x", Smi::cast(obj)->value());
   1223           break;
   1224         case 'i':
   1225           msg.Append("%i", Smi::cast(obj)->value());
   1226           break;
   1227         default:
   1228           UNREACHABLE();
   1229       }
   1230     } else {
   1231       msg.Append(c);
   1232     }
   1233   }
   1234   msg.Append('\n');
   1235   msg.WriteToLogFile();
   1236 }
   1237 
   1238 
   1239 void Logger::ApiIndexedSecurityCheck(uint32_t index) {
   1240   if (!log_->IsEnabled() || !FLAG_log_api) return;
   1241   ApiEvent("api,check-security,%u\n", index);
   1242 }
   1243 
   1244 
   1245 void Logger::ApiNamedPropertyAccess(const char* tag,
   1246                                     JSObject* holder,
   1247                                     Object* name) {
   1248   ASSERT(name->IsName());
   1249   if (!log_->IsEnabled() || !FLAG_log_api) return;
   1250   String* class_name_obj = holder->class_name();
   1251   SmartArrayPointer<char> class_name =
   1252       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1253   if (name->IsString()) {
   1254     SmartArrayPointer<char> property_name =
   1255         String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1256     ApiEvent("api,%s,\"%s\",\"%s\"\n", tag, *class_name, *property_name);
   1257   } else {
   1258     Symbol* symbol = Symbol::cast(name);
   1259     uint32_t hash = symbol->Hash();
   1260     if (symbol->name()->IsUndefined()) {
   1261       ApiEvent("api,%s,\"%s\",symbol(hash %x)\n", tag, *class_name, hash);
   1262     } else {
   1263       SmartArrayPointer<char> str = String::cast(symbol->name())->ToCString(
   1264           DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1265       ApiEvent("api,%s,\"%s\",symbol(\"%s\" hash %x)\n",
   1266                tag, *class_name, *str, hash);
   1267     }
   1268   }
   1269 }
   1270 
   1271 void Logger::ApiIndexedPropertyAccess(const char* tag,
   1272                                       JSObject* holder,
   1273                                       uint32_t index) {
   1274   if (!log_->IsEnabled() || !FLAG_log_api) return;
   1275   String* class_name_obj = holder->class_name();
   1276   SmartArrayPointer<char> class_name =
   1277       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1278   ApiEvent("api,%s,\"%s\",%u\n", tag, *class_name, index);
   1279 }
   1280 
   1281 
   1282 void Logger::ApiObjectAccess(const char* tag, JSObject* object) {
   1283   if (!log_->IsEnabled() || !FLAG_log_api) return;
   1284   String* class_name_obj = object->class_name();
   1285   SmartArrayPointer<char> class_name =
   1286       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1287   ApiEvent("api,%s,\"%s\"\n", tag, *class_name);
   1288 }
   1289 
   1290 
   1291 void Logger::ApiEntryCall(const char* name) {
   1292   if (!log_->IsEnabled() || !FLAG_log_api) return;
   1293   ApiEvent("api,%s\n", name);
   1294 }
   1295 
   1296 
   1297 void Logger::NewEvent(const char* name, void* object, size_t size) {
   1298   if (!log_->IsEnabled() || !FLAG_log) return;
   1299   Log::MessageBuilder msg(log_);
   1300   msg.Append("new,%s,0x%" V8PRIxPTR ",%u\n", name, object,
   1301              static_cast<unsigned int>(size));
   1302   msg.WriteToLogFile();
   1303 }
   1304 
   1305 
   1306 void Logger::DeleteEvent(const char* name, void* object) {
   1307   if (!log_->IsEnabled() || !FLAG_log) return;
   1308   Log::MessageBuilder msg(log_);
   1309   msg.Append("delete,%s,0x%" V8PRIxPTR "\n", name, object);
   1310   msg.WriteToLogFile();
   1311 }
   1312 
   1313 
   1314 void Logger::NewEventStatic(const char* name, void* object, size_t size) {
   1315   Isolate::Current()->logger()->NewEvent(name, object, size);
   1316 }
   1317 
   1318 
   1319 void Logger::DeleteEventStatic(const char* name, void* object) {
   1320   Isolate::Current()->logger()->DeleteEvent(name, object);
   1321 }
   1322 
   1323 
   1324 void Logger::CallbackEventInternal(const char* prefix, Name* name,
   1325                                    Address entry_point) {
   1326   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1327   Log::MessageBuilder msg(log_);
   1328   msg.Append("%s,%s,-2,",
   1329              kLogEventsNames[CODE_CREATION_EVENT],
   1330              kLogEventsNames[CALLBACK_TAG]);
   1331   msg.AppendAddress(entry_point);
   1332   if (name->IsString()) {
   1333     SmartArrayPointer<char> str =
   1334         String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1335     msg.Append(",1,\"%s%s\"", prefix, *str);
   1336   } else {
   1337     Symbol* symbol = Symbol::cast(name);
   1338     if (symbol->name()->IsUndefined()) {
   1339       msg.Append(",1,symbol(hash %x)", prefix, symbol->Hash());
   1340     } else {
   1341       SmartArrayPointer<char> str = String::cast(symbol->name())->ToCString(
   1342           DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1343       msg.Append(",1,symbol(\"%s\" hash %x)", prefix, *str, symbol->Hash());
   1344     }
   1345   }
   1346   msg.Append('\n');
   1347   msg.WriteToLogFile();
   1348 }
   1349 
   1350 
   1351 void Logger::CallbackEvent(Name* name, Address entry_point) {
   1352   PROFILER_LOG(CallbackEvent(name, entry_point));
   1353   CallbackEventInternal("", name, entry_point);
   1354 }
   1355 
   1356 
   1357 void Logger::GetterCallbackEvent(Name* name, Address entry_point) {
   1358   PROFILER_LOG(GetterCallbackEvent(name, entry_point));
   1359   CallbackEventInternal("get ", name, entry_point);
   1360 }
   1361 
   1362 
   1363 void Logger::SetterCallbackEvent(Name* name, Address entry_point) {
   1364   PROFILER_LOG(SetterCallbackEvent(name, entry_point));
   1365   CallbackEventInternal("set ", name, entry_point);
   1366 }
   1367 
   1368 
   1369 static void AppendCodeCreateHeader(Log::MessageBuilder* msg,
   1370                                    Logger::LogEventsAndTags tag,
   1371                                    Code* code) {
   1372   ASSERT(msg);
   1373   msg->Append("%s,%s,%d,",
   1374               kLogEventsNames[Logger::CODE_CREATION_EVENT],
   1375               kLogEventsNames[tag],
   1376               code->kind());
   1377   msg->AppendAddress(code->address());
   1378   msg->Append(",%d,", code->ExecutableSize());
   1379 }
   1380 
   1381 
   1382 void Logger::CodeCreateEvent(LogEventsAndTags tag,
   1383                              Code* code,
   1384                              const char* comment) {
   1385   PROFILER_LOG(CodeCreateEvent(tag, code, comment));
   1386 
   1387   if (!is_logging_code_events()) return;
   1388   CALL_LISTENERS(CodeCreateEvent(tag, code, comment));
   1389 
   1390   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1391   Log::MessageBuilder msg(log_);
   1392   AppendCodeCreateHeader(&msg, tag, code);
   1393   msg.AppendDoubleQuotedString(comment);
   1394   msg.Append('\n');
   1395   msg.WriteToLogFile();
   1396 }
   1397 
   1398 
   1399 void Logger::CodeCreateEvent(LogEventsAndTags tag,
   1400                              Code* code,
   1401                              Name* name) {
   1402   PROFILER_LOG(CodeCreateEvent(tag, code, name));
   1403 
   1404   if (!is_logging_code_events()) return;
   1405   CALL_LISTENERS(CodeCreateEvent(tag, code, name));
   1406 
   1407   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1408   Log::MessageBuilder msg(log_);
   1409   AppendCodeCreateHeader(&msg, tag, code);
   1410   if (name->IsString()) {
   1411     msg.Append('"');
   1412     msg.AppendDetailed(String::cast(name), false);
   1413     msg.Append('"');
   1414   } else {
   1415     msg.AppendSymbolName(Symbol::cast(name));
   1416   }
   1417   msg.Append('\n');
   1418   msg.WriteToLogFile();
   1419 }
   1420 
   1421 
   1422 void Logger::CodeCreateEvent(LogEventsAndTags tag,
   1423                              Code* code,
   1424                              SharedFunctionInfo* shared,
   1425                              CompilationInfo* info,
   1426                              Name* name) {
   1427   PROFILER_LOG(CodeCreateEvent(tag, code, shared, info, name));
   1428 
   1429   if (!is_logging_code_events()) return;
   1430   CALL_LISTENERS(CodeCreateEvent(tag, code, shared, info, name));
   1431 
   1432   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1433   if (code == isolate_->builtins()->builtin(
   1434       Builtins::kLazyCompile))
   1435     return;
   1436 
   1437   Log::MessageBuilder msg(log_);
   1438   AppendCodeCreateHeader(&msg, tag, code);
   1439   if (name->IsString()) {
   1440     SmartArrayPointer<char> str =
   1441         String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1442     msg.Append("\"%s\"", *str);
   1443   } else {
   1444     msg.AppendSymbolName(Symbol::cast(name));
   1445   }
   1446   msg.Append(',');
   1447   msg.AppendAddress(shared->address());
   1448   msg.Append(",%s", ComputeMarker(code));
   1449   msg.Append('\n');
   1450   msg.WriteToLogFile();
   1451 }
   1452 
   1453 
   1454 // Although, it is possible to extract source and line from
   1455 // the SharedFunctionInfo object, we left it to caller
   1456 // to leave logging functions free from heap allocations.
   1457 void Logger::CodeCreateEvent(LogEventsAndTags tag,
   1458                              Code* code,
   1459                              SharedFunctionInfo* shared,
   1460                              CompilationInfo* info,
   1461                              Name* source, int line, int column) {
   1462   PROFILER_LOG(CodeCreateEvent(tag, code, shared, info, source, line, column));
   1463 
   1464   if (!is_logging_code_events()) return;
   1465   CALL_LISTENERS(CodeCreateEvent(tag, code, shared, info, source, line,
   1466                                  column));
   1467 
   1468   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1469   Log::MessageBuilder msg(log_);
   1470   AppendCodeCreateHeader(&msg, tag, code);
   1471   SmartArrayPointer<char> name =
   1472       shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1473   msg.Append("\"%s ", *name);
   1474   if (source->IsString()) {
   1475     SmartArrayPointer<char> sourcestr =
   1476        String::cast(source)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   1477     msg.Append("%s", *sourcestr);
   1478   } else {
   1479     msg.AppendSymbolName(Symbol::cast(source));
   1480   }
   1481   msg.Append(":%d:%d\",", line, column);
   1482   msg.AppendAddress(shared->address());
   1483   msg.Append(",%s", ComputeMarker(code));
   1484   msg.Append('\n');
   1485   msg.WriteToLogFile();
   1486 }
   1487 
   1488 
   1489 void Logger::CodeCreateEvent(LogEventsAndTags tag,
   1490                              Code* code,
   1491                              int args_count) {
   1492   PROFILER_LOG(CodeCreateEvent(tag, code, args_count));
   1493 
   1494   if (!is_logging_code_events()) return;
   1495   CALL_LISTENERS(CodeCreateEvent(tag, code, args_count));
   1496 
   1497   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1498   Log::MessageBuilder msg(log_);
   1499   AppendCodeCreateHeader(&msg, tag, code);
   1500   msg.Append("\"args_count: %d\"", args_count);
   1501   msg.Append('\n');
   1502   msg.WriteToLogFile();
   1503 }
   1504 
   1505 
   1506 void Logger::CodeMovingGCEvent() {
   1507   PROFILER_LOG(CodeMovingGCEvent());
   1508 
   1509   if (!is_logging_code_events()) return;
   1510   if (!log_->IsEnabled() || !FLAG_ll_prof) return;
   1511   CALL_LISTENERS(CodeMovingGCEvent());
   1512   OS::SignalCodeMovingGC();
   1513 }
   1514 
   1515 
   1516 void Logger::RegExpCodeCreateEvent(Code* code, String* source) {
   1517   PROFILER_LOG(RegExpCodeCreateEvent(code, source));
   1518 
   1519   if (!is_logging_code_events()) return;
   1520   CALL_LISTENERS(RegExpCodeCreateEvent(code, source));
   1521 
   1522   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1523   Log::MessageBuilder msg(log_);
   1524   AppendCodeCreateHeader(&msg, REG_EXP_TAG, code);
   1525   msg.Append('"');
   1526   msg.AppendDetailed(source, false);
   1527   msg.Append('"');
   1528   msg.Append('\n');
   1529   msg.WriteToLogFile();
   1530 }
   1531 
   1532 
   1533 void Logger::CodeMoveEvent(Address from, Address to) {
   1534   PROFILER_LOG(CodeMoveEvent(from, to));
   1535 
   1536   if (!is_logging_code_events()) return;
   1537   CALL_LISTENERS(CodeMoveEvent(from, to));
   1538   MoveEventInternal(CODE_MOVE_EVENT, from, to);
   1539 }
   1540 
   1541 
   1542 void Logger::CodeDeleteEvent(Address from) {
   1543   PROFILER_LOG(CodeDeleteEvent(from));
   1544 
   1545   if (!is_logging_code_events()) return;
   1546   CALL_LISTENERS(CodeDeleteEvent(from));
   1547 
   1548   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1549   Log::MessageBuilder msg(log_);
   1550   msg.Append("%s,", kLogEventsNames[CODE_DELETE_EVENT]);
   1551   msg.AppendAddress(from);
   1552   msg.Append('\n');
   1553   msg.WriteToLogFile();
   1554 }
   1555 
   1556 
   1557 void Logger::CodeLinePosInfoAddPositionEvent(void* jit_handler_data,
   1558                                      int pc_offset,
   1559                                      int position) {
   1560   JIT_LOG(AddCodeLinePosInfoEvent(jit_handler_data,
   1561                                   pc_offset,
   1562                                   position,
   1563                                   JitCodeEvent::POSITION));
   1564 }
   1565 
   1566 
   1567 void Logger::CodeLinePosInfoAddStatementPositionEvent(void* jit_handler_data,
   1568                                                       int pc_offset,
   1569                                                       int position) {
   1570   JIT_LOG(AddCodeLinePosInfoEvent(jit_handler_data,
   1571                                   pc_offset,
   1572                                   position,
   1573                                   JitCodeEvent::STATEMENT_POSITION));
   1574 }
   1575 
   1576 
   1577 void Logger::CodeStartLinePosInfoRecordEvent(PositionsRecorder* pos_recorder) {
   1578   if (jit_logger_ != NULL) {
   1579       pos_recorder->AttachJITHandlerData(jit_logger_->StartCodePosInfoEvent());
   1580   }
   1581 }
   1582 
   1583 
   1584 void Logger::CodeEndLinePosInfoRecordEvent(Code* code,
   1585                                            void* jit_handler_data) {
   1586   JIT_LOG(EndCodePosInfoEvent(code, jit_handler_data));
   1587 }
   1588 
   1589 
   1590 void Logger::CodeNameEvent(Address addr, int pos, const char* code_name) {
   1591   if (code_name == NULL) return;  // Not a code object.
   1592   Log::MessageBuilder msg(log_);
   1593   msg.Append("%s,%d,", kLogEventsNames[SNAPSHOT_CODE_NAME_EVENT], pos);
   1594   msg.AppendDoubleQuotedString(code_name);
   1595   msg.Append("\n");
   1596   msg.WriteToLogFile();
   1597 }
   1598 
   1599 
   1600 void Logger::SnapshotPositionEvent(Address addr, int pos) {
   1601   if (!log_->IsEnabled()) return;
   1602   LL_LOG(SnapshotPositionEvent(addr, pos));
   1603   if (!FLAG_log_snapshot_positions) return;
   1604   Log::MessageBuilder msg(log_);
   1605   msg.Append("%s,", kLogEventsNames[SNAPSHOT_POSITION_EVENT]);
   1606   msg.AppendAddress(addr);
   1607   msg.Append(",%d", pos);
   1608   msg.Append('\n');
   1609   msg.WriteToLogFile();
   1610 }
   1611 
   1612 
   1613 void Logger::SharedFunctionInfoMoveEvent(Address from, Address to) {
   1614   PROFILER_LOG(SharedFunctionInfoMoveEvent(from, to));
   1615 
   1616   if (!is_logging_code_events()) return;
   1617   MoveEventInternal(SHARED_FUNC_MOVE_EVENT, from, to);
   1618 }
   1619 
   1620 
   1621 void Logger::MoveEventInternal(LogEventsAndTags event,
   1622                                Address from,
   1623                                Address to) {
   1624   if (!FLAG_log_code || !log_->IsEnabled()) return;
   1625   Log::MessageBuilder msg(log_);
   1626   msg.Append("%s,", kLogEventsNames[event]);
   1627   msg.AppendAddress(from);
   1628   msg.Append(',');
   1629   msg.AppendAddress(to);
   1630   msg.Append('\n');
   1631   msg.WriteToLogFile();
   1632 }
   1633 
   1634 
   1635 void Logger::ResourceEvent(const char* name, const char* tag) {
   1636   if (!log_->IsEnabled() || !FLAG_log) return;
   1637   Log::MessageBuilder msg(log_);
   1638   msg.Append("%s,%s,", name, tag);
   1639 
   1640   uint32_t sec, usec;
   1641   if (OS::GetUserTime(&sec, &usec) != -1) {
   1642     msg.Append("%d,%d,", sec, usec);
   1643   }
   1644   msg.Append("%.0f", OS::TimeCurrentMillis());
   1645 
   1646   msg.Append('\n');
   1647   msg.WriteToLogFile();
   1648 }
   1649 
   1650 
   1651 void Logger::SuspectReadEvent(Name* name, Object* obj) {
   1652   if (!log_->IsEnabled() || !FLAG_log_suspect) return;
   1653   Log::MessageBuilder msg(log_);
   1654   String* class_name = obj->IsJSObject()
   1655                        ? JSObject::cast(obj)->class_name()
   1656                        : isolate_->heap()->empty_string();
   1657   msg.Append("suspect-read,");
   1658   msg.Append(class_name);
   1659   msg.Append(',');
   1660   if (name->IsString()) {
   1661     msg.Append('"');
   1662     msg.Append(String::cast(name));
   1663     msg.Append('"');
   1664   } else {
   1665     msg.AppendSymbolName(Symbol::cast(name));
   1666   }
   1667   msg.Append('\n');
   1668   msg.WriteToLogFile();
   1669 }
   1670 
   1671 
   1672 void Logger::HeapSampleBeginEvent(const char* space, const char* kind) {
   1673   if (!log_->IsEnabled() || !FLAG_log_gc) return;
   1674   Log::MessageBuilder msg(log_);
   1675   // Using non-relative system time in order to be able to synchronize with
   1676   // external memory profiling events (e.g. DOM memory size).
   1677   msg.Append("heap-sample-begin,\"%s\",\"%s\",%.0f\n",
   1678              space, kind, OS::TimeCurrentMillis());
   1679   msg.WriteToLogFile();
   1680 }
   1681 
   1682 
   1683 void Logger::HeapSampleEndEvent(const char* space, const char* kind) {
   1684   if (!log_->IsEnabled() || !FLAG_log_gc) return;
   1685   Log::MessageBuilder msg(log_);
   1686   msg.Append("heap-sample-end,\"%s\",\"%s\"\n", space, kind);
   1687   msg.WriteToLogFile();
   1688 }
   1689 
   1690 
   1691 void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) {
   1692   if (!log_->IsEnabled() || !FLAG_log_gc) return;
   1693   Log::MessageBuilder msg(log_);
   1694   msg.Append("heap-sample-item,%s,%d,%d\n", type, number, bytes);
   1695   msg.WriteToLogFile();
   1696 }
   1697 
   1698 
   1699 void Logger::DebugTag(const char* call_site_tag) {
   1700   if (!log_->IsEnabled() || !FLAG_log) return;
   1701   Log::MessageBuilder msg(log_);
   1702   msg.Append("debug-tag,%s\n", call_site_tag);
   1703   msg.WriteToLogFile();
   1704 }
   1705 
   1706 
   1707 void Logger::DebugEvent(const char* event_type, Vector<uint16_t> parameter) {
   1708   if (!log_->IsEnabled() || !FLAG_log) return;
   1709   StringBuilder s(parameter.length() + 1);
   1710   for (int i = 0; i < parameter.length(); ++i) {
   1711     s.AddCharacter(static_cast<char>(parameter[i]));
   1712   }
   1713   char* parameter_string = s.Finalize();
   1714   Log::MessageBuilder msg(log_);
   1715   msg.Append("debug-queue-event,%s,%15.3f,%s\n",
   1716              event_type,
   1717              OS::TimeCurrentMillis(),
   1718              parameter_string);
   1719   DeleteArray(parameter_string);
   1720   msg.WriteToLogFile();
   1721 }
   1722 
   1723 
   1724 void Logger::TickEvent(TickSample* sample, bool overflow) {
   1725   if (!log_->IsEnabled() || !FLAG_prof) return;
   1726   Log::MessageBuilder msg(log_);
   1727   msg.Append("%s,", kLogEventsNames[TICK_EVENT]);
   1728   msg.AppendAddress(sample->pc);
   1729   msg.Append(",%ld", static_cast<int>(timer_.Elapsed().InMicroseconds()));
   1730   if (sample->has_external_callback) {
   1731     msg.Append(",1,");
   1732     msg.AppendAddress(sample->external_callback);
   1733   } else {
   1734     msg.Append(",0,");
   1735     msg.AppendAddress(sample->tos);
   1736   }
   1737   msg.Append(",%d", static_cast<int>(sample->state));
   1738   if (overflow) {
   1739     msg.Append(",overflow");
   1740   }
   1741   for (int i = 0; i < sample->frames_count; ++i) {
   1742     msg.Append(',');
   1743     msg.AppendAddress(sample->stack[i]);
   1744   }
   1745   msg.Append('\n');
   1746   msg.WriteToLogFile();
   1747 }
   1748 
   1749 
   1750 void Logger::StopProfiler() {
   1751   if (!log_->IsEnabled()) return;
   1752   if (profiler_ != NULL) {
   1753     profiler_->pause();
   1754     is_logging_ = false;
   1755   }
   1756 }
   1757 
   1758 
   1759 // This function can be called when Log's mutex is acquired,
   1760 // either from main or Profiler's thread.
   1761 void Logger::LogFailure() {
   1762   StopProfiler();
   1763 }
   1764 
   1765 
   1766 class EnumerateOptimizedFunctionsVisitor: public OptimizedFunctionVisitor {
   1767  public:
   1768   EnumerateOptimizedFunctionsVisitor(Handle<SharedFunctionInfo>* sfis,
   1769                                      Handle<Code>* code_objects,
   1770                                      int* count)
   1771       : sfis_(sfis), code_objects_(code_objects), count_(count) { }
   1772 
   1773   virtual void EnterContext(Context* context) {}
   1774   virtual void LeaveContext(Context* context) {}
   1775 
   1776   virtual void VisitFunction(JSFunction* function) {
   1777     SharedFunctionInfo* sfi = SharedFunctionInfo::cast(function->shared());
   1778     Object* maybe_script = sfi->script();
   1779     if (maybe_script->IsScript()
   1780         && !Script::cast(maybe_script)->HasValidSource()) return;
   1781     if (sfis_ != NULL) {
   1782       sfis_[*count_] = Handle<SharedFunctionInfo>(sfi);
   1783     }
   1784     if (code_objects_ != NULL) {
   1785       ASSERT(function->code()->kind() == Code::OPTIMIZED_FUNCTION);
   1786       code_objects_[*count_] = Handle<Code>(function->code());
   1787     }
   1788     *count_ = *count_ + 1;
   1789   }
   1790 
   1791  private:
   1792   Handle<SharedFunctionInfo>* sfis_;
   1793   Handle<Code>* code_objects_;
   1794   int* count_;
   1795 };
   1796 
   1797 
   1798 static int EnumerateCompiledFunctions(Heap* heap,
   1799                                       Handle<SharedFunctionInfo>* sfis,
   1800                                       Handle<Code>* code_objects) {
   1801   HeapIterator iterator(heap);
   1802   DisallowHeapAllocation no_gc;
   1803   int compiled_funcs_count = 0;
   1804 
   1805   // Iterate the heap to find shared function info objects and record
   1806   // the unoptimized code for them.
   1807   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
   1808     if (!obj->IsSharedFunctionInfo()) continue;
   1809     SharedFunctionInfo* sfi = SharedFunctionInfo::cast(obj);
   1810     if (sfi->is_compiled()
   1811         && (!sfi->script()->IsScript()
   1812             || Script::cast(sfi->script())->HasValidSource())) {
   1813       if (sfis != NULL) {
   1814         sfis[compiled_funcs_count] = Handle<SharedFunctionInfo>(sfi);
   1815       }
   1816       if (code_objects != NULL) {
   1817         code_objects[compiled_funcs_count] = Handle<Code>(sfi->code());
   1818       }
   1819       ++compiled_funcs_count;
   1820     }
   1821   }
   1822 
   1823   // Iterate all optimized functions in all contexts.
   1824   EnumerateOptimizedFunctionsVisitor visitor(sfis,
   1825                                              code_objects,
   1826                                              &compiled_funcs_count);
   1827   Deoptimizer::VisitAllOptimizedFunctions(heap->isolate(), &visitor);
   1828 
   1829   return compiled_funcs_count;
   1830 }
   1831 
   1832 
   1833 void Logger::LogCodeObject(Object* object) {
   1834   Code* code_object = Code::cast(object);
   1835   LogEventsAndTags tag = Logger::STUB_TAG;
   1836   const char* description = "Unknown code from the snapshot";
   1837   switch (code_object->kind()) {
   1838     case Code::FUNCTION:
   1839     case Code::OPTIMIZED_FUNCTION:
   1840       return;  // We log this later using LogCompiledFunctions.
   1841     case Code::BINARY_OP_IC:
   1842     case Code::COMPARE_IC:  // fall through
   1843     case Code::COMPARE_NIL_IC:   // fall through
   1844     case Code::TO_BOOLEAN_IC:  // fall through
   1845     case Code::STUB:
   1846       description =
   1847           CodeStub::MajorName(CodeStub::GetMajorKey(code_object), true);
   1848       if (description == NULL)
   1849         description = "A stub from the snapshot";
   1850       tag = Logger::STUB_TAG;
   1851       break;
   1852     case Code::REGEXP:
   1853       description = "Regular expression code";
   1854       tag = Logger::REG_EXP_TAG;
   1855       break;
   1856     case Code::BUILTIN:
   1857       description = "A builtin from the snapshot";
   1858       tag = Logger::BUILTIN_TAG;
   1859       break;
   1860     case Code::HANDLER:
   1861       description = "An IC handler from the snapshot";
   1862       tag = Logger::HANDLER_TAG;
   1863       break;
   1864     case Code::KEYED_LOAD_IC:
   1865       description = "A keyed load IC from the snapshot";
   1866       tag = Logger::KEYED_LOAD_IC_TAG;
   1867       break;
   1868     case Code::LOAD_IC:
   1869       description = "A load IC from the snapshot";
   1870       tag = Logger::LOAD_IC_TAG;
   1871       break;
   1872     case Code::STORE_IC:
   1873       description = "A store IC from the snapshot";
   1874       tag = Logger::STORE_IC_TAG;
   1875       break;
   1876     case Code::KEYED_STORE_IC:
   1877       description = "A keyed store IC from the snapshot";
   1878       tag = Logger::KEYED_STORE_IC_TAG;
   1879       break;
   1880     case Code::CALL_IC:
   1881       description = "A call IC from the snapshot";
   1882       tag = Logger::CALL_IC_TAG;
   1883       break;
   1884     case Code::KEYED_CALL_IC:
   1885       description = "A keyed call IC from the snapshot";
   1886       tag = Logger::KEYED_CALL_IC_TAG;
   1887       break;
   1888     case Code::NUMBER_OF_KINDS:
   1889       break;
   1890   }
   1891   PROFILE(isolate_, CodeCreateEvent(tag, code_object, description));
   1892 }
   1893 
   1894 
   1895 void Logger::LogCodeObjects() {
   1896   Heap* heap = isolate_->heap();
   1897   heap->CollectAllGarbage(Heap::kMakeHeapIterableMask,
   1898                           "Logger::LogCodeObjects");
   1899   HeapIterator iterator(heap);
   1900   DisallowHeapAllocation no_gc;
   1901   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
   1902     if (obj->IsCode()) LogCodeObject(obj);
   1903   }
   1904 }
   1905 
   1906 
   1907 void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared,
   1908                                  Handle<Code> code) {
   1909   Handle<String> func_name(shared->DebugName());
   1910   if (shared->script()->IsScript()) {
   1911     Handle<Script> script(Script::cast(shared->script()));
   1912     int line_num = GetScriptLineNumber(script, shared->start_position()) + 1;
   1913     int column_num =
   1914         GetScriptColumnNumber(script, shared->start_position()) + 1;
   1915     if (script->name()->IsString()) {
   1916       Handle<String> script_name(String::cast(script->name()));
   1917       if (line_num > 0) {
   1918         PROFILE(isolate_,
   1919                 CodeCreateEvent(
   1920                     Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG, *script),
   1921                     *code, *shared, NULL,
   1922                     *script_name, line_num, column_num));
   1923       } else {
   1924         // Can't distinguish eval and script here, so always use Script.
   1925         PROFILE(isolate_,
   1926                 CodeCreateEvent(
   1927                     Logger::ToNativeByScript(Logger::SCRIPT_TAG, *script),
   1928                     *code, *shared, NULL, *script_name));
   1929       }
   1930     } else {
   1931       PROFILE(isolate_,
   1932               CodeCreateEvent(
   1933                   Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG, *script),
   1934                   *code, *shared, NULL,
   1935                   isolate_->heap()->empty_string(), line_num, column_num));
   1936     }
   1937   } else if (shared->IsApiFunction()) {
   1938     // API function.
   1939     FunctionTemplateInfo* fun_data = shared->get_api_func_data();
   1940     Object* raw_call_data = fun_data->call_code();
   1941     if (!raw_call_data->IsUndefined()) {
   1942       CallHandlerInfo* call_data = CallHandlerInfo::cast(raw_call_data);
   1943       Object* callback_obj = call_data->callback();
   1944       Address entry_point = v8::ToCData<Address>(callback_obj);
   1945       PROFILE(isolate_, CallbackEvent(*func_name, entry_point));
   1946     }
   1947   } else {
   1948     PROFILE(isolate_,
   1949             CodeCreateEvent(
   1950                 Logger::LAZY_COMPILE_TAG, *code, *shared, NULL, *func_name));
   1951   }
   1952 }
   1953 
   1954 
   1955 void Logger::LogCompiledFunctions() {
   1956   Heap* heap = isolate_->heap();
   1957   heap->CollectAllGarbage(Heap::kMakeHeapIterableMask,
   1958                           "Logger::LogCompiledFunctions");
   1959   HandleScope scope(isolate_);
   1960   const int compiled_funcs_count = EnumerateCompiledFunctions(heap, NULL, NULL);
   1961   ScopedVector< Handle<SharedFunctionInfo> > sfis(compiled_funcs_count);
   1962   ScopedVector< Handle<Code> > code_objects(compiled_funcs_count);
   1963   EnumerateCompiledFunctions(heap, sfis.start(), code_objects.start());
   1964 
   1965   // During iteration, there can be heap allocation due to
   1966   // GetScriptLineNumber call.
   1967   for (int i = 0; i < compiled_funcs_count; ++i) {
   1968     if (*code_objects[i] == isolate_->builtins()->builtin(
   1969         Builtins::kLazyCompile))
   1970       continue;
   1971     LogExistingFunction(sfis[i], code_objects[i]);
   1972   }
   1973 }
   1974 
   1975 
   1976 void Logger::LogAccessorCallbacks() {
   1977   Heap* heap = isolate_->heap();
   1978   heap->CollectAllGarbage(Heap::kMakeHeapIterableMask,
   1979                           "Logger::LogAccessorCallbacks");
   1980   HeapIterator iterator(heap);
   1981   DisallowHeapAllocation no_gc;
   1982   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
   1983     if (!obj->IsExecutableAccessorInfo()) continue;
   1984     ExecutableAccessorInfo* ai = ExecutableAccessorInfo::cast(obj);
   1985     if (!ai->name()->IsName()) continue;
   1986     Address getter_entry = v8::ToCData<Address>(ai->getter());
   1987     Name* name = Name::cast(ai->name());
   1988     if (getter_entry != 0) {
   1989       PROFILE(isolate_, GetterCallbackEvent(name, getter_entry));
   1990     }
   1991     Address setter_entry = v8::ToCData<Address>(ai->setter());
   1992     if (setter_entry != 0) {
   1993       PROFILE(isolate_, SetterCallbackEvent(name, setter_entry));
   1994     }
   1995   }
   1996 }
   1997 
   1998 
   1999 static void AddIsolateIdIfNeeded(Isolate* isolate, StringStream* stream) {
   2000   if (isolate->IsDefaultIsolate() || !FLAG_logfile_per_isolate) return;
   2001   stream->Add("isolate-%p-", isolate);
   2002 }
   2003 
   2004 
   2005 static SmartArrayPointer<const char> PrepareLogFileName(
   2006     Isolate* isolate, const char* file_name) {
   2007   if (strchr(file_name, '%') != NULL || !isolate->IsDefaultIsolate()) {
   2008     // If there's a '%' in the log file name we have to expand
   2009     // placeholders.
   2010     HeapStringAllocator allocator;
   2011     StringStream stream(&allocator);
   2012     AddIsolateIdIfNeeded(isolate, &stream);
   2013     for (const char* p = file_name; *p; p++) {
   2014       if (*p == '%') {
   2015         p++;
   2016         switch (*p) {
   2017           case '\0':
   2018             // If there's a % at the end of the string we back up
   2019             // one character so we can escape the loop properly.
   2020             p--;
   2021             break;
   2022           case 'p':
   2023             stream.Add("%d", OS::GetCurrentProcessId());
   2024             break;
   2025           case 't': {
   2026             // %t expands to the current time in milliseconds.
   2027             double time = OS::TimeCurrentMillis();
   2028             stream.Add("%.0f", FmtElm(time));
   2029             break;
   2030           }
   2031           case '%':
   2032             // %% expands (contracts really) to %.
   2033             stream.Put('%');
   2034             break;
   2035           default:
   2036             // All other %'s expand to themselves.
   2037             stream.Put('%');
   2038             stream.Put(*p);
   2039             break;
   2040         }
   2041       } else {
   2042         stream.Put(*p);
   2043       }
   2044     }
   2045     return SmartArrayPointer<const char>(stream.ToCString());
   2046   }
   2047   int length = StrLength(file_name);
   2048   char* str = NewArray<char>(length + 1);
   2049   OS::MemCopy(str, file_name, length);
   2050   str[length] = '\0';
   2051   return SmartArrayPointer<const char>(str);
   2052 }
   2053 
   2054 
   2055 bool Logger::SetUp(Isolate* isolate) {
   2056   // Tests and EnsureInitialize() can call this twice in a row. It's harmless.
   2057   if (is_initialized_) return true;
   2058   is_initialized_ = true;
   2059 
   2060   // --ll-prof implies --log-code and --log-snapshot-positions.
   2061   if (FLAG_ll_prof) {
   2062     FLAG_log_snapshot_positions = true;
   2063   }
   2064 
   2065   SmartArrayPointer<const char> log_file_name =
   2066       PrepareLogFileName(isolate, FLAG_logfile);
   2067   log_->Initialize(*log_file_name);
   2068 
   2069 
   2070   if (FLAG_perf_basic_prof) {
   2071     perf_basic_logger_ = new PerfBasicLogger();
   2072     addCodeEventListener(perf_basic_logger_);
   2073   }
   2074 
   2075   if (FLAG_perf_jit_prof) {
   2076     perf_jit_logger_ = new PerfJitLogger();
   2077     addCodeEventListener(perf_jit_logger_);
   2078   }
   2079 
   2080   if (FLAG_ll_prof) {
   2081     ll_logger_ = new LowLevelLogger(*log_file_name);
   2082     addCodeEventListener(ll_logger_);
   2083   }
   2084 
   2085   ticker_ = new Ticker(isolate, kSamplingIntervalMs);
   2086 
   2087   if (Log::InitLogAtStart()) {
   2088     is_logging_ = true;
   2089   }
   2090 
   2091   if (FLAG_prof) {
   2092     profiler_ = new Profiler(isolate);
   2093     is_logging_ = true;
   2094     profiler_->Engage();
   2095   }
   2096 
   2097   if (FLAG_log_internal_timer_events || FLAG_prof) timer_.Start();
   2098 
   2099   return true;
   2100 }
   2101 
   2102 
   2103 void Logger::SetCodeEventHandler(uint32_t options,
   2104                                  JitCodeEventHandler event_handler) {
   2105   if (jit_logger_) {
   2106       removeCodeEventListener(jit_logger_);
   2107       delete jit_logger_;
   2108       jit_logger_ = NULL;
   2109   }
   2110 
   2111   if (event_handler) {
   2112     jit_logger_ = new JitLogger(event_handler);
   2113     addCodeEventListener(jit_logger_);
   2114     if (options & kJitCodeEventEnumExisting) {
   2115       HandleScope scope(isolate_);
   2116       LogCodeObjects();
   2117       LogCompiledFunctions();
   2118     }
   2119   }
   2120 }
   2121 
   2122 
   2123 Sampler* Logger::sampler() {
   2124   return ticker_;
   2125 }
   2126 
   2127 
   2128 FILE* Logger::TearDown() {
   2129   if (!is_initialized_) return NULL;
   2130   is_initialized_ = false;
   2131 
   2132   // Stop the profiler before closing the file.
   2133   if (profiler_ != NULL) {
   2134     profiler_->Disengage();
   2135     delete profiler_;
   2136     profiler_ = NULL;
   2137   }
   2138 
   2139   delete ticker_;
   2140   ticker_ = NULL;
   2141 
   2142   if (perf_basic_logger_) {
   2143     removeCodeEventListener(perf_basic_logger_);
   2144     delete perf_basic_logger_;
   2145     perf_basic_logger_ = NULL;
   2146   }
   2147 
   2148   if (perf_jit_logger_) {
   2149     removeCodeEventListener(perf_jit_logger_);
   2150     delete perf_jit_logger_;
   2151     perf_jit_logger_ = NULL;
   2152   }
   2153 
   2154   if (ll_logger_) {
   2155     removeCodeEventListener(ll_logger_);
   2156     delete ll_logger_;
   2157     ll_logger_ = NULL;
   2158   }
   2159 
   2160   if (jit_logger_) {
   2161     removeCodeEventListener(jit_logger_);
   2162     delete jit_logger_;
   2163     jit_logger_ = NULL;
   2164   }
   2165 
   2166   return log_->Close();
   2167 }
   2168 
   2169 } }  // namespace v8::internal
   2170