src/v8/src/log.cc

   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.get());
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.get(),
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.get(),
1257              property_name.get());
1258   } else {
1259     Symbol* symbol = Symbol::cast(name);
1260     uint32_t hash = symbol->Hash();
1261     if (symbol->name()->IsUndefined()) {
1262       ApiEvent("api,%s,\"%s\",symbol(hash %x)\n", tag, class_name.get(), hash);
1263     } else {
1264       SmartArrayPointer<char> str = String::cast(symbol->name())->ToCString(
1265           DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
1266       ApiEvent("api,%s,\"%s\",symbol(\"%s\" hash %x)\n",
1267                tag, class_name.get(), str.get(), hash);
1268     }
1269   }
1270 }
1271
1272 void Logger::ApiIndexedPropertyAccess(const char* tag,
1273                                       JSObject* holder,
1274                                       uint32_t index) {
1275   if (!log_->IsEnabled() || !FLAG_log_api) return;
1276   String* class_name_obj = holder->class_name();
1277   SmartArrayPointer<char> class_name =
1278       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
1279   ApiEvent("api,%s,\"%s\",%u\n", tag, class_name.get(), index);
1280 }
1281
1282
1283 void Logger::ApiObjectAccess(const char* tag, JSObject* object) {
1284   if (!log_->IsEnabled() || !FLAG_log_api) return;
1285   String* class_name_obj = object->class_name();
1286   SmartArrayPointer<char> class_name =
1287       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
1288   ApiEvent("api,%s,\"%s\"\n", tag, class_name.get());
1289 }
1290
1291
1292 void Logger::ApiEntryCall(const char* name) {
1293   if (!log_->IsEnabled() || !FLAG_log_api) return;
1294   ApiEvent("api,%s\n", name);
1295 }
1296
1297
1298 void Logger::NewEvent(const char* name, void* object, size_t size) {
1299   if (!log_->IsEnabled() || !FLAG_log) return;
1300   Log::MessageBuilder msg(log_);
1301   msg.Append("new,%s,0x%" V8PRIxPTR ",%u\n", name, object,
1302              static_cast<unsigned int>(size));
1303   msg.WriteToLogFile();
1304 }
1305
1306
1307 void Logger::DeleteEvent(const char* name, void* object) {
1308   if (!log_->IsEnabled() || !FLAG_log) return;
1309   Log::MessageBuilder msg(log_);
1310   msg.Append("delete,%s,0x%" V8PRIxPTR "\n", name, object);
1311   msg.WriteToLogFile();
1312 }
1313
1314
1315 void Logger::NewEventStatic(const char* name, void* object, size_t size) {
1316   Isolate::Current()->logger()->NewEvent(name, object, size);
1317 }
1318
1319
1320 void Logger::DeleteEventStatic(const char* name, void* object) {
1321   Isolate::Current()->logger()->DeleteEvent(name, object);
1322 }
1323
1324
1325 void Logger::CallbackEventInternal(const char* prefix, Name* name,
1326                                    Address entry_point) {
1327   if (!FLAG_log_code || !log_->IsEnabled()) return;
1328   Log::MessageBuilder msg(log_);
1329   msg.Append("%s,%s,-2,",
1330              kLogEventsNames[CODE_CREATION_EVENT],
1331              kLogEventsNames[CALLBACK_TAG]);
1332   msg.AppendAddress(entry_point);
1333   if (name->IsString()) {
1334     SmartArrayPointer<char> str =
1335         String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
1336     msg.Append(",1,\"%s%s\"", prefix, str.get());
1337   } else {
1338     Symbol* symbol = Symbol::cast(name);
1339     if (symbol->name()->IsUndefined()) {
1340       msg.Append(",1,symbol(hash %x)", prefix, symbol->Hash());
1341     } else {
1342       SmartArrayPointer<char> str = String::cast(symbol->name())->ToCString(
1343           DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
1344       msg.Append(",1,symbol(\"%s\" hash %x)", prefix, str.get(),
1345                  symbol->Hash());
1346     }
1347   }
1348   msg.Append('\n');
1349   msg.WriteToLogFile();
1350 }
1351
1352
1353 void Logger::CallbackEvent(Name* name, Address entry_point) {
1354   PROFILER_LOG(CallbackEvent(name, entry_point));
1355   CallbackEventInternal("", name, entry_point);
1356 }
1357
1358
1359 void Logger::GetterCallbackEvent(Name* name, Address entry_point) {
1360   PROFILER_LOG(GetterCallbackEvent(name, entry_point));
1361   CallbackEventInternal("get ", name, entry_point);
1362 }
1363
1364
1365 void Logger::SetterCallbackEvent(Name* name, Address entry_point) {
1366   PROFILER_LOG(SetterCallbackEvent(name, entry_point));
1367   CallbackEventInternal("set ", name, entry_point);
1368 }
1369
1370
1371 static void AppendCodeCreateHeader(Log::MessageBuilder* msg,
1372                                    Logger::LogEventsAndTags tag,
1373                                    Code* code) {
1374   ASSERT(msg);
1375   msg->Append("%s,%s,%d,",
1376               kLogEventsNames[Logger::CODE_CREATION_EVENT],
1377               kLogEventsNames[tag],
1378               code->kind());
1379   msg->AppendAddress(code->address());
1380   msg->Append(",%d,", code->ExecutableSize());
1381 }
1382
1383
1384 void Logger::CodeCreateEvent(LogEventsAndTags tag,
1385                              Code* code,
1386                              const char* comment) {
1387   PROFILER_LOG(CodeCreateEvent(tag, code, comment));
1388
1389   if (!is_logging_code_events()) return;
1390   CALL_LISTENERS(CodeCreateEvent(tag, code, comment));
1391
1392   if (!FLAG_log_code || !log_->IsEnabled()) return;
1393   Log::MessageBuilder msg(log_);
1394   AppendCodeCreateHeader(&msg, tag, code);
1395   msg.AppendDoubleQuotedString(comment);
1396   msg.Append('\n');
1397   msg.WriteToLogFile();
1398 }
1399
1400
1401 void Logger::CodeCreateEvent(LogEventsAndTags tag,
1402                              Code* code,
1403                              Name* name) {
1404   PROFILER_LOG(CodeCreateEvent(tag, code, name));
1405
1406   if (!is_logging_code_events()) return;
1407   CALL_LISTENERS(CodeCreateEvent(tag, code, name));
1408
1409   if (!FLAG_log_code || !log_->IsEnabled()) return;
1410   Log::MessageBuilder msg(log_);
1411   AppendCodeCreateHeader(&msg, tag, code);
1412   if (name->IsString()) {
1413     msg.Append('"');
1414     msg.AppendDetailed(String::cast(name), false);
1415     msg.Append('"');
1416   } else {
1417     msg.AppendSymbolName(Symbol::cast(name));
1418   }
1419   msg.Append('\n');
1420   msg.WriteToLogFile();
1421 }
1422
1423
1424 void Logger::CodeCreateEvent(LogEventsAndTags tag,
1425                              Code* code,
1426                              SharedFunctionInfo* shared,
1427                              CompilationInfo* info,
1428                              Name* name) {
1429   PROFILER_LOG(CodeCreateEvent(tag, code, shared, info, name));
1430
1431   if (!is_logging_code_events()) return;
1432   CALL_LISTENERS(CodeCreateEvent(tag, code, shared, info, name));
1433
1434   if (!FLAG_log_code || !log_->IsEnabled()) return;
1435   if (code == isolate_->builtins()->builtin(Builtins::kCompileUnoptimized))
1436     return;
1437
1438   Log::MessageBuilder msg(log_);
1439   AppendCodeCreateHeader(&msg, tag, code);
1440   if (name->IsString()) {
1441     SmartArrayPointer<char> str =
1442         String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
1443     msg.Append("\"%s\"", str.get());
1444   } else {
1445     msg.AppendSymbolName(Symbol::cast(name));
1446   }
1447   msg.Append(',');
1448   msg.AppendAddress(shared->address());
1449   msg.Append(",%s", ComputeMarker(code));
1450   msg.Append('\n');
1451   msg.WriteToLogFile();
1452 }
1453
1454
1455 // Although, it is possible to extract source and line from
1456 // the SharedFunctionInfo object, we left it to caller
1457 // to leave logging functions free from heap allocations.
1458 void Logger::CodeCreateEvent(LogEventsAndTags tag,
1459                              Code* code,
1460                              SharedFunctionInfo* shared,
1461                              CompilationInfo* info,
1462                              Name* source, int line, int column) {
1463   PROFILER_LOG(CodeCreateEvent(tag, code, shared, info, source, line, column));
1464
1465   if (!is_logging_code_events()) return;
1466   CALL_LISTENERS(CodeCreateEvent(tag, code, shared, info, source, line,
1467                                  column));
1468
1469   if (!FLAG_log_code || !log_->IsEnabled()) return;
1470   Log::MessageBuilder msg(log_);
1471   AppendCodeCreateHeader(&msg, tag, code);
1472   SmartArrayPointer<char> name =
1473       shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
1474   msg.Append("\"%s ", name.get());
1475   if (source->IsString()) {
1476     SmartArrayPointer<char> sourcestr =
1477        String::cast(source)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
1478     msg.Append("%s", sourcestr.get());
1479   } else {
1480     msg.AppendSymbolName(Symbol::cast(source));
1481   }
1482   msg.Append(":%d:%d\",", line, column);
1483   msg.AppendAddress(shared->address());
1484   msg.Append(",%s", ComputeMarker(code));
1485   msg.Append('\n');
1486   msg.WriteToLogFile();
1487 }
1488
1489
1490 void Logger::CodeCreateEvent(LogEventsAndTags tag,
1491                              Code* code,
1492                              int args_count) {
1493   PROFILER_LOG(CodeCreateEvent(tag, code, args_count));
1494
1495   if (!is_logging_code_events()) return;
1496   CALL_LISTENERS(CodeCreateEvent(tag, code, args_count));
1497
1498   if (!FLAG_log_code || !log_->IsEnabled()) return;
1499   Log::MessageBuilder msg(log_);
1500   AppendCodeCreateHeader(&msg, tag, code);
1501   msg.Append("\"args_count: %d\"", args_count);
1502   msg.Append('\n');
1503   msg.WriteToLogFile();
1504 }
1505
1506
1507 void Logger::CodeMovingGCEvent() {
1508   PROFILER_LOG(CodeMovingGCEvent());
1509
1510   if (!is_logging_code_events()) return;
1511   if (!log_->IsEnabled() || !FLAG_ll_prof) return;
1512   CALL_LISTENERS(CodeMovingGCEvent());
1513   OS::SignalCodeMovingGC();
1514 }
1515
1516
1517 void Logger::RegExpCodeCreateEvent(Code* code, String* source) {
1518   PROFILER_LOG(RegExpCodeCreateEvent(code, source));
1519
1520   if (!is_logging_code_events()) return;
1521   CALL_LISTENERS(RegExpCodeCreateEvent(code, source));
1522
1523   if (!FLAG_log_code || !log_->IsEnabled()) return;
1524   Log::MessageBuilder msg(log_);
1525   AppendCodeCreateHeader(&msg, REG_EXP_TAG, code);
1526   msg.Append('"');
1527   msg.AppendDetailed(source, false);
1528   msg.Append('"');
1529   msg.Append('\n');
1530   msg.WriteToLogFile();
1531 }
1532
1533
1534 void Logger::CodeMoveEvent(Address from, Address to) {
1535   PROFILER_LOG(CodeMoveEvent(from, to));
1536
1537   if (!is_logging_code_events()) return;
1538   CALL_LISTENERS(CodeMoveEvent(from, to));
1539   MoveEventInternal(CODE_MOVE_EVENT, from, to);
1540 }
1541
1542
1543 void Logger::CodeDeleteEvent(Address from) {
1544   PROFILER_LOG(CodeDeleteEvent(from));
1545
1546   if (!is_logging_code_events()) return;
1547   CALL_LISTENERS(CodeDeleteEvent(from));
1548
1549   if (!FLAG_log_code || !log_->IsEnabled()) return;
1550   Log::MessageBuilder msg(log_);
1551   msg.Append("%s,", kLogEventsNames[CODE_DELETE_EVENT]);
1552   msg.AppendAddress(from);
1553   msg.Append('\n');
1554   msg.WriteToLogFile();
1555 }
1556
1557
1558 void Logger::CodeLinePosInfoAddPositionEvent(void* jit_handler_data,
1559                                      int pc_offset,
1560                                      int position) {
1561   JIT_LOG(AddCodeLinePosInfoEvent(jit_handler_data,
1562                                   pc_offset,
1563                                   position,
1564                                   JitCodeEvent::POSITION));
1565 }
1566
1567
1568 void Logger::CodeLinePosInfoAddStatementPositionEvent(void* jit_handler_data,
1569                                                       int pc_offset,
1570                                                       int position) {
1571   JIT_LOG(AddCodeLinePosInfoEvent(jit_handler_data,
1572                                   pc_offset,
1573                                   position,
1574                                   JitCodeEvent::STATEMENT_POSITION));
1575 }
1576
1577
1578 void Logger::CodeStartLinePosInfoRecordEvent(PositionsRecorder* pos_recorder) {
1579   if (jit_logger_ != NULL) {
1580       pos_recorder->AttachJITHandlerData(jit_logger_->StartCodePosInfoEvent());
1581   }
1582 }
1583
1584
1585 void Logger::CodeEndLinePosInfoRecordEvent(Code* code,
1586                                            void* jit_handler_data) {
1587   JIT_LOG(EndCodePosInfoEvent(code, jit_handler_data));
1588 }
1589
1590
1591 void Logger::CodeNameEvent(Address addr, int pos, const char* code_name) {
1592   if (code_name == NULL) return;  // Not a code object.
1593   Log::MessageBuilder msg(log_);
1594   msg.Append("%s,%d,", kLogEventsNames[SNAPSHOT_CODE_NAME_EVENT], pos);
1595   msg.AppendDoubleQuotedString(code_name);
1596   msg.Append("\n");
1597   msg.WriteToLogFile();
1598 }
1599
1600
1601 void Logger::SnapshotPositionEvent(Address addr, int pos) {
1602   if (!log_->IsEnabled()) return;
1603   LL_LOG(SnapshotPositionEvent(addr, pos));
1604   if (!FLAG_log_snapshot_positions) return;
1605   Log::MessageBuilder msg(log_);
1606   msg.Append("%s,", kLogEventsNames[SNAPSHOT_POSITION_EVENT]);
1607   msg.AppendAddress(addr);
1608   msg.Append(",%d", pos);
1609   msg.Append('\n');
1610   msg.WriteToLogFile();
1611 }
1612
1613
1614 void Logger::SharedFunctionInfoMoveEvent(Address from, Address to) {
1615   PROFILER_LOG(SharedFunctionInfoMoveEvent(from, to));
1616
1617   if (!is_logging_code_events()) return;
1618   MoveEventInternal(SHARED_FUNC_MOVE_EVENT, from, to);
1619 }
1620
1621
1622 void Logger::MoveEventInternal(LogEventsAndTags event,
1623                                Address from,
1624                                Address to) {
1625   if (!FLAG_log_code || !log_->IsEnabled()) return;
1626   Log::MessageBuilder msg(log_);
1627   msg.Append("%s,", kLogEventsNames[event]);
1628   msg.AppendAddress(from);
1629   msg.Append(',');
1630   msg.AppendAddress(to);
1631   msg.Append('\n');
1632   msg.WriteToLogFile();
1633 }
1634
1635
1636 void Logger::ResourceEvent(const char* name, const char* tag) {
1637   if (!log_->IsEnabled() || !FLAG_log) return;
1638   Log::MessageBuilder msg(log_);
1639   msg.Append("%s,%s,", name, tag);
1640
1641   uint32_t sec, usec;
1642   if (OS::GetUserTime(&sec, &usec) != -1) {
1643     msg.Append("%d,%d,", sec, usec);
1644   }
1645   msg.Append("%.0f", OS::TimeCurrentMillis());
1646
1647   msg.Append('\n');
1648   msg.WriteToLogFile();
1649 }
1650
1651
1652 void Logger::SuspectReadEvent(Name* name, Object* obj) {
1653   if (!log_->IsEnabled() || !FLAG_log_suspect) return;
1654   Log::MessageBuilder msg(log_);
1655   String* class_name = obj->IsJSObject()
1656                        ? JSObject::cast(obj)->class_name()
1657                        : isolate_->heap()->empty_string();
1658   msg.Append("suspect-read,");
1659   msg.Append(class_name);
1660   msg.Append(',');
1661   if (name->IsString()) {
1662     msg.Append('"');
1663     msg.Append(String::cast(name));
1664     msg.Append('"');
1665   } else {
1666     msg.AppendSymbolName(Symbol::cast(name));
1667   }
1668   msg.Append('\n');
1669   msg.WriteToLogFile();
1670 }
1671
1672
1673 void Logger::HeapSampleBeginEvent(const char* space, const char* kind) {
1674   if (!log_->IsEnabled() || !FLAG_log_gc) return;
1675   Log::MessageBuilder msg(log_);
1676   // Using non-relative system time in order to be able to synchronize with
1677   // external memory profiling events (e.g. DOM memory size).
1678   msg.Append("heap-sample-begin,\"%s\",\"%s\",%.0f\n",
1679              space, kind, OS::TimeCurrentMillis());
1680   msg.WriteToLogFile();
1681 }
1682
1683
1684 void Logger::HeapSampleEndEvent(const char* space, const char* kind) {
1685   if (!log_->IsEnabled() || !FLAG_log_gc) return;
1686   Log::MessageBuilder msg(log_);
1687   msg.Append("heap-sample-end,\"%s\",\"%s\"\n", space, kind);
1688   msg.WriteToLogFile();
1689 }
1690
1691
1692 void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) {
1693   if (!log_->IsEnabled() || !FLAG_log_gc) return;
1694   Log::MessageBuilder msg(log_);
1695   msg.Append("heap-sample-item,%s,%d,%d\n", type, number, bytes);
1696   msg.WriteToLogFile();
1697 }
1698
1699
1700 void Logger::DebugTag(const char* call_site_tag) {
1701   if (!log_->IsEnabled() || !FLAG_log) return;
1702   Log::MessageBuilder msg(log_);
1703   msg.Append("debug-tag,%s\n", call_site_tag);
1704   msg.WriteToLogFile();
1705 }
1706
1707
1708 void Logger::DebugEvent(const char* event_type, Vector<uint16_t> parameter) {
1709   if (!log_->IsEnabled() || !FLAG_log) return;
1710   StringBuilder s(parameter.length() + 1);
1711   for (int i = 0; i < parameter.length(); ++i) {
1712     s.AddCharacter(static_cast<char>(parameter[i]));
1713   }
1714   char* parameter_string = s.Finalize();
1715   Log::MessageBuilder msg(log_);
1716   msg.Append("debug-queue-event,%s,%15.3f,%s\n",
1717              event_type,
1718              OS::TimeCurrentMillis(),
1719              parameter_string);
1720   DeleteArray(parameter_string);
1721   msg.WriteToLogFile();
1722 }
1723
1724
1725 void Logger::TickEvent(TickSample* sample, bool overflow) {
1726   if (!log_->IsEnabled() || !FLAG_prof) return;
1727   Log::MessageBuilder msg(log_);
1728   msg.Append("%s,", kLogEventsNames[TICK_EVENT]);
1729   msg.AppendAddress(sample->pc);
1730   msg.Append(",%ld", static_cast<int>(timer_.Elapsed().InMicroseconds()));
1731   if (sample->has_external_callback) {
1732     msg.Append(",1,");
1733     msg.AppendAddress(sample->external_callback);
1734   } else {
1735     msg.Append(",0,");
1736     msg.AppendAddress(sample->tos);
1737   }
1738   msg.Append(",%d", static_cast<int>(sample->state));
1739   if (overflow) {
1740     msg.Append(",overflow");
1741   }
1742   for (int i = 0; i < sample->frames_count; ++i) {
1743     msg.Append(',');
1744     msg.AppendAddress(sample->stack[i]);
1745   }
1746   msg.Append('\n');
1747   msg.WriteToLogFile();
1748 }
1749
1750
1751 void Logger::StopProfiler() {
1752   if (!log_->IsEnabled()) return;
1753   if (profiler_ != NULL) {
1754     profiler_->pause();
1755     is_logging_ = false;
1756   }
1757 }
1758
1759
1760 // This function can be called when Log's mutex is acquired,
1761 // either from main or Profiler's thread.
1762 void Logger::LogFailure() {
1763   StopProfiler();
1764 }
1765
1766
1767 class EnumerateOptimizedFunctionsVisitor: public OptimizedFunctionVisitor {
1768  public:
1769   EnumerateOptimizedFunctionsVisitor(Handle<SharedFunctionInfo>* sfis,
1770                                      Handle<Code>* code_objects,
1771                                      int* count)
1772       : sfis_(sfis), code_objects_(code_objects), count_(count) { }
1773
1774   virtual void EnterContext(Context* context) {}
1775   virtual void LeaveContext(Context* context) {}
1776
1777   virtual void VisitFunction(JSFunction* function) {
1778     SharedFunctionInfo* sfi = SharedFunctionInfo::cast(function->shared());
1779     Object* maybe_script = sfi->script();
1780     if (maybe_script->IsScript()
1781         && !Script::cast(maybe_script)->HasValidSource()) return;
1782     if (sfis_ != NULL) {
1783       sfis_[*count_] = Handle<SharedFunctionInfo>(sfi);
1784     }
1785     if (code_objects_ != NULL) {
1786       ASSERT(function->code()->kind() == Code::OPTIMIZED_FUNCTION);
1787       code_objects_[*count_] = Handle<Code>(function->code());
1788     }
1789     *count_ = *count_ + 1;
1790   }
1791
1792  private:
1793   Handle<SharedFunctionInfo>* sfis_;
1794   Handle<Code>* code_objects_;
1795   int* count_;
1796 };
1797
1798
1799 static int EnumerateCompiledFunctions(Heap* heap,
1800                                       Handle<SharedFunctionInfo>* sfis,
1801                                       Handle<Code>* code_objects) {
1802   HeapIterator iterator(heap);
1803   DisallowHeapAllocation no_gc;
1804   int compiled_funcs_count = 0;
1805
1806   // Iterate the heap to find shared function info objects and record
1807   // the unoptimized code for them.
1808   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
1809     if (!obj->IsSharedFunctionInfo()) continue;
1810     SharedFunctionInfo* sfi = SharedFunctionInfo::cast(obj);
1811     if (sfi->is_compiled()
1812         && (!sfi->script()->IsScript()
1813             || Script::cast(sfi->script())->HasValidSource())) {
1814       if (sfis != NULL) {
1815         sfis[compiled_funcs_count] = Handle<SharedFunctionInfo>(sfi);
1816       }
1817       if (code_objects != NULL) {
1818         code_objects[compiled_funcs_count] = Handle<Code>(sfi->code());
1819       }
1820       ++compiled_funcs_count;
1821     }
1822   }
1823
1824   // Iterate all optimized functions in all contexts.
1825   EnumerateOptimizedFunctionsVisitor visitor(sfis,
1826                                              code_objects,
1827                                              &compiled_funcs_count);
1828   Deoptimizer::VisitAllOptimizedFunctions(heap->isolate(), &visitor);
1829
1830   return compiled_funcs_count;
1831 }
1832
1833
1834 void Logger::LogCodeObject(Object* object) {
1835   Code* code_object = Code::cast(object);
1836   LogEventsAndTags tag = Logger::STUB_TAG;
1837   const char* description = "Unknown code from the snapshot";
1838   switch (code_object->kind()) {
1839     case Code::FUNCTION:
1840     case Code::OPTIMIZED_FUNCTION:
1841       return;  // We log this later using LogCompiledFunctions.
1842     case Code::BINARY_OP_IC:
1843     case Code::COMPARE_IC:  // fall through
1844     case Code::COMPARE_NIL_IC:   // fall through
1845     case Code::TO_BOOLEAN_IC:  // fall through
1846     case Code::STUB:
1847       description =
1848           CodeStub::MajorName(CodeStub::GetMajorKey(code_object), true);
1849       if (description == NULL)
1850         description = "A stub from the snapshot";
1851       tag = Logger::STUB_TAG;
1852       break;
1853     case Code::REGEXP:
1854       description = "Regular expression code";
1855       tag = Logger::REG_EXP_TAG;
1856       break;
1857     case Code::BUILTIN:
1858       description = "A builtin from the snapshot";
1859       tag = Logger::BUILTIN_TAG;
1860       break;
1861     case Code::HANDLER:
1862       description = "An IC handler from the snapshot";
1863       tag = Logger::HANDLER_TAG;
1864       break;
1865     case Code::KEYED_LOAD_IC:
1866       description = "A keyed load IC from the snapshot";
1867       tag = Logger::KEYED_LOAD_IC_TAG;
1868       break;
1869     case Code::LOAD_IC:
1870       description = "A load IC from the snapshot";
1871       tag = Logger::LOAD_IC_TAG;
1872       break;
1873     case Code::STORE_IC:
1874       description = "A store IC from the snapshot";
1875       tag = Logger::STORE_IC_TAG;
1876       break;
1877     case Code::KEYED_STORE_IC:
1878       description = "A keyed store IC from the snapshot";
1879       tag = Logger::KEYED_STORE_IC_TAG;
1880       break;
1881     case Code::NUMBER_OF_KINDS:
1882       break;
1883   }
1884   PROFILE(isolate_, CodeCreateEvent(tag, code_object, description));
1885 }
1886
1887
1888 void Logger::LogCodeObjects() {
1889   Heap* heap = isolate_->heap();
1890   heap->CollectAllGarbage(Heap::kMakeHeapIterableMask,
1891                           "Logger::LogCodeObjects");
1892   HeapIterator iterator(heap);
1893   DisallowHeapAllocation no_gc;
1894   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
1895     if (obj->IsCode()) LogCodeObject(obj);
1896   }
1897 }
1898
1899
1900 void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared,
1901                                  Handle<Code> code) {
1902   Handle<String> func_name(shared->DebugName());
1903   if (shared->script()->IsScript()) {
1904     Handle<Script> script(Script::cast(shared->script()));
1905     int line_num = GetScriptLineNumber(script, shared->start_position()) + 1;
1906     int column_num =
1907         GetScriptColumnNumber(script, shared->start_position()) + 1;
1908     if (script->name()->IsString()) {
1909       Handle<String> script_name(String::cast(script->name()));
1910       if (line_num > 0) {
1911         PROFILE(isolate_,
1912                 CodeCreateEvent(
1913                     Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG, *script),
1914                     *code, *shared, NULL,
1915                     *script_name, line_num, column_num));
1916       } else {
1917         // Can't distinguish eval and script here, so always use Script.
1918         PROFILE(isolate_,
1919                 CodeCreateEvent(
1920                     Logger::ToNativeByScript(Logger::SCRIPT_TAG, *script),
1921                     *code, *shared, NULL, *script_name));
1922       }
1923     } else {
1924       PROFILE(isolate_,
1925               CodeCreateEvent(
1926                   Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG, *script),
1927                   *code, *shared, NULL,
1928                   isolate_->heap()->empty_string(), line_num, column_num));
1929     }
1930   } else if (shared->IsApiFunction()) {
1931     // API function.
1932     FunctionTemplateInfo* fun_data = shared->get_api_func_data();
1933     Object* raw_call_data = fun_data->call_code();
1934     if (!raw_call_data->IsUndefined()) {
1935       CallHandlerInfo* call_data = CallHandlerInfo::cast(raw_call_data);
1936       Object* callback_obj = call_data->callback();
1937       Address entry_point = v8::ToCData<Address>(callback_obj);
1938       PROFILE(isolate_, CallbackEvent(*func_name, entry_point));
1939     }
1940   } else {
1941     PROFILE(isolate_,
1942             CodeCreateEvent(
1943                 Logger::LAZY_COMPILE_TAG, *code, *shared, NULL, *func_name));
1944   }
1945 }
1946
1947
1948 void Logger::LogCompiledFunctions() {
1949   Heap* heap = isolate_->heap();
1950   heap->CollectAllGarbage(Heap::kMakeHeapIterableMask,
1951                           "Logger::LogCompiledFunctions");
1952   HandleScope scope(isolate_);
1953   const int compiled_funcs_count = EnumerateCompiledFunctions(heap, NULL, NULL);
1954   ScopedVector< Handle<SharedFunctionInfo> > sfis(compiled_funcs_count);
1955   ScopedVector< Handle<Code> > code_objects(compiled_funcs_count);
1956   EnumerateCompiledFunctions(heap, sfis.start(), code_objects.start());
1957
1958   // During iteration, there can be heap allocation due to
1959   // GetScriptLineNumber call.
1960   for (int i = 0; i < compiled_funcs_count; ++i) {
1961     if (code_objects[i].is_identical_to(
1962             isolate_->builtins()->CompileUnoptimized()))
1963       continue;
1964     LogExistingFunction(sfis[i], code_objects[i]);
1965   }
1966 }
1967
1968
1969 void Logger::LogAccessorCallbacks() {
1970   Heap* heap = isolate_->heap();
1971   heap->CollectAllGarbage(Heap::kMakeHeapIterableMask,
1972                           "Logger::LogAccessorCallbacks");
1973   HeapIterator iterator(heap);
1974   DisallowHeapAllocation no_gc;
1975   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
1976     if (!obj->IsExecutableAccessorInfo()) continue;
1977     ExecutableAccessorInfo* ai = ExecutableAccessorInfo::cast(obj);
1978     if (!ai->name()->IsName()) continue;
1979     Address getter_entry = v8::ToCData<Address>(ai->getter());
1980     Name* name = Name::cast(ai->name());
1981     if (getter_entry != 0) {
1982       PROFILE(isolate_, GetterCallbackEvent(name, getter_entry));
1983     }
1984     Address setter_entry = v8::ToCData<Address>(ai->setter());
1985     if (setter_entry != 0) {
1986       PROFILE(isolate_, SetterCallbackEvent(name, setter_entry));
1987     }
1988   }
1989 }
1990
1991
1992 static void AddIsolateIdIfNeeded(Isolate* isolate, StringStream* stream) {
1993   if (isolate->IsDefaultIsolate() || !FLAG_logfile_per_isolate) return;
1994   stream->Add("isolate-%p-", isolate);
1995 }
1996
1997
1998 static SmartArrayPointer<const char> PrepareLogFileName(
1999     Isolate* isolate, const char* file_name) {
2000   if (strchr(file_name, '%') != NULL || !isolate->IsDefaultIsolate()) {
2001     // If there's a '%' in the log file name we have to expand
2002     // placeholders.
2003     HeapStringAllocator allocator;
2004     StringStream stream(&allocator);
2005     AddIsolateIdIfNeeded(isolate, &stream);
2006     for (const char* p = file_name; *p; p++) {
2007       if (*p == '%') {
2008         p++;
2009         switch (*p) {
2010           case '\0':
2011             // If there's a % at the end of the string we back up
2012             // one character so we can escape the loop properly.
2013             p--;
2014             break;
2015           case 'p':
2016             stream.Add("%d", OS::GetCurrentProcessId());
2017             break;
2018           case 't': {
2019             // %t expands to the current time in milliseconds.
2020             double time = OS::TimeCurrentMillis();
2021             stream.Add("%.0f", FmtElm(time));
2022             break;
2023           }
2024           case '%':
2025             // %% expands (contracts really) to %.
2026             stream.Put('%');
2027             break;
2028           default:
2029             // All other %'s expand to themselves.
2030             stream.Put('%');
2031             stream.Put(*p);
2032             break;
2033         }
2034       } else {
2035         stream.Put(*p);
2036       }
2037     }
2038     return SmartArrayPointer<const char>(stream.ToCString());
2039   }
2040   int length = StrLength(file_name);
2041   char* str = NewArray<char>(length + 1);
2042   OS::MemCopy(str, file_name, length);
2043   str[length] = '\0';
2044   return SmartArrayPointer<const char>(str);
2045 }
2046
2047
2048 bool Logger::SetUp(Isolate* isolate) {
2049   // Tests and EnsureInitialize() can call this twice in a row. It's harmless.
2050   if (is_initialized_) return true;
2051   is_initialized_ = true;
2052
2053   // --ll-prof implies --log-code and --log-snapshot-positions.
2054   if (FLAG_ll_prof) {
2055     FLAG_log_snapshot_positions = true;
2056   }
2057
2058   SmartArrayPointer<const char> log_file_name =
2059       PrepareLogFileName(isolate, FLAG_logfile);
2060   log_->Initialize(log_file_name.get());
2061
2062
2063   if (FLAG_perf_basic_prof) {
2064     perf_basic_logger_ = new PerfBasicLogger();
2065     addCodeEventListener(perf_basic_logger_);
2066   }
2067
2068   if (FLAG_perf_jit_prof) {
2069     perf_jit_logger_ = new PerfJitLogger();
2070     addCodeEventListener(perf_jit_logger_);
2071   }
2072
2073   if (FLAG_ll_prof) {
2074     ll_logger_ = new LowLevelLogger(log_file_name.get());
2075     addCodeEventListener(ll_logger_);
2076   }
2077
2078   ticker_ = new Ticker(isolate, kSamplingIntervalMs);
2079
2080   if (Log::InitLogAtStart()) {
2081     is_logging_ = true;
2082   }
2083
2084   if (FLAG_prof) {
2085     profiler_ = new Profiler(isolate);
2086     is_logging_ = true;
2087     profiler_->Engage();
2088   }
2089
2090   if (FLAG_log_internal_timer_events || FLAG_prof) timer_.Start();
2091
2092   return true;
2093 }
2094
2095
2096 void Logger::SetCodeEventHandler(uint32_t options,
2097                                  JitCodeEventHandler event_handler) {
2098   if (jit_logger_) {
2099       removeCodeEventListener(jit_logger_);
2100       delete jit_logger_;
2101       jit_logger_ = NULL;
2102   }
2103
2104   if (event_handler) {
2105     jit_logger_ = new JitLogger(event_handler);
2106     addCodeEventListener(jit_logger_);
2107     if (options & kJitCodeEventEnumExisting) {
2108       HandleScope scope(isolate_);
2109       LogCodeObjects();
2110       LogCompiledFunctions();
2111     }
2112   }
2113 }
2114
2115
2116 Sampler* Logger::sampler() {
2117   return ticker_;
2118 }
2119
2120
2121 FILE* Logger::TearDown() {
2122   if (!is_initialized_) return NULL;
2123   is_initialized_ = false;
2124
2125   // Stop the profiler before closing the file.
2126   if (profiler_ != NULL) {
2127     profiler_->Disengage();
2128     delete profiler_;
2129     profiler_ = NULL;
2130   }
2131
2132   delete ticker_;
2133   ticker_ = NULL;
2134
2135   if (perf_basic_logger_) {
2136     removeCodeEventListener(perf_basic_logger_);
2137     delete perf_basic_logger_;
2138     perf_basic_logger_ = NULL;
2139   }
2140
2141   if (perf_jit_logger_) {
2142     removeCodeEventListener(perf_jit_logger_);
2143     delete perf_jit_logger_;
2144     perf_jit_logger_ = NULL;
2145   }
2146
2147   if (ll_logger_) {
2148     removeCodeEventListener(ll_logger_);
2149     delete ll_logger_;
2150     ll_logger_ = NULL;
2151   }
2152
2153   if (jit_logger_) {
2154     removeCodeEventListener(jit_logger_);
2155     delete jit_logger_;
2156     jit_logger_ = NULL;
2157   }
2158
2159   return log_->Close();
2160 }
2161
2162 } }  // namespace v8::internal