src/v8/src/log.cc

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