CSE2410 Fall 2014 Bounce

// Copyright 2011 the V8 project authors. All rights reserved.

// Redistribution and use in source and binary forms, with or without

// modification, are permitted provided that the following conditions are

// met:

//

//     * Redistributions of source code must retain the above copyright

//       notice, this list of conditions and the following disclaimer.

//     * Redistributions in binary form must reproduce the above

//       copyright notice, this list of conditions and the following

//       disclaimer in the documentation and/or other materials provided

//       with the distribution.

//     * Neither the name of Google Inc. nor the names of its

//       contributors may be used to endorse or promote products derived

//       from this software without specific prior written permission.

//

// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS

// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT

// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR

// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT

// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,

// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT

// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,

// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY

// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT

// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE

// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.

#include <stdarg.h>

#include "v8.h"

#include "bootstrapper.h"

#include "code-stubs.h"

#include "cpu-profiler.h"

#include "deoptimizer.h"

#include "global-handles.h"

#include "log.h"

#include "log-utils.h"

#include "macro-assembler.h"

#include "platform.h"

#include "runtime-profiler.h"

#include "serialize.h"

#include "string-stream.h"

#include "vm-state-inl.h"

namespace v8 {

namespace internal {

#define DECLARE_EVENT(ignore1, name) name,

static const char* const kLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = {

  LOG_EVENTS_AND_TAGS_LIST(DECLARE_EVENT)

};

#undef DECLARE_EVENT

#define CALL_LISTENERS(Call)                    \

for (int i = 0; i < listeners_.length(); ++i) { \

  listeners_[i]->Call;                          \

}

#define PROFILER_LOG(Call)                                \

  do {                                                    \

    CpuProfiler* cpu_profiler = isolate_->cpu_profiler(); \

    if (cpu_profiler->is_profiling()) {                   \

      cpu_profiler->Call;                                 \

    }                                                     \

  } while (false);

// ComputeMarker must only be used when SharedFunctionInfo is known.

static const char* ComputeMarker(Code* code) {

  switch (code->kind()) {

    case Code::FUNCTION: return code->optimizable() ? "~" : "";

    case Code::OPTIMIZED_FUNCTION: return "*";

    default: return "";

  }

}

class CodeEventLogger::NameBuffer {

 public:

  NameBuffer() { Reset(); }

  void Reset() {

    utf8_pos_ = 0;

  }

  void Init(Logger::LogEventsAndTags tag) {

    Reset();

    AppendBytes(kLogEventsNames[tag]);

    AppendByte(':');

  }

  void AppendName(Name* name) {

    if (name->IsString()) {

      AppendString(String::cast(name));

    } else {

      Symbol* symbol = Symbol::cast(name);

      AppendBytes("symbol(");

      if (!symbol->name()->IsUndefined()) {

        AppendBytes("\"");

        AppendString(String::cast(symbol->name()));

        AppendBytes("\" ");

      }

      AppendBytes("hash ");

      AppendHex(symbol->Hash());

      AppendByte(')');

    }

  }

  void AppendString(String* str) {

    if (str == NULL) return;

    int uc16_length = Min(str->length(), kUtf16BufferSize);

    String::WriteToFlat(str, utf16_buffer, 0, uc16_length);

    int previous = unibrow::Utf16::kNoPreviousCharacter;

    for (int i = 0; i < uc16_length && utf8_pos_ < kUtf8BufferSize; ++i) {

      uc16 c = utf16_buffer[i];

      if (c <= unibrow::Utf8::kMaxOneByteChar) {

        utf8_buffer_[utf8_pos_++] = static_cast<char>(c);

      } else {

        int char_length = unibrow::Utf8::Length(c, previous);

        if (utf8_pos_ + char_length > kUtf8BufferSize) break;

        unibrow::Utf8::Encode(utf8_buffer_ + utf8_pos_, c, previous);

        utf8_pos_ += char_length;

      }

      previous = c;

    }

  }

  void AppendBytes(const char* bytes, int size) {

    size = Min(size, kUtf8BufferSize - utf8_pos_);

    OS::MemCopy(utf8_buffer_ + utf8_pos_, bytes, size);

    utf8_pos_ += size;

  }

  void AppendBytes(const char* bytes) {

    AppendBytes(bytes, StrLength(bytes));

  }

  void AppendByte(char c) {

    if (utf8_pos_ >= kUtf8BufferSize) return;

    utf8_buffer_[utf8_pos_++] = c;

  }

  void AppendInt(int n) {

    Vector<char> buffer(utf8_buffer_ + utf8_pos_,

                        kUtf8BufferSize - utf8_pos_);

    int size = OS::SNPrintF(buffer, "%d", n);

    if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {

      utf8_pos_ += size;

    }

  }

  void AppendHex(uint32_t n) {

    Vector<char> buffer(utf8_buffer_ + utf8_pos_,

                        kUtf8BufferSize - utf8_pos_);

    int size = OS::SNPrintF(buffer, "%x", n);

    if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {

      utf8_pos_ += size;

    }

  }

  const char* get() { return utf8_buffer_; }

  int size() const { return utf8_pos_; }

 private:

  static const int kUtf8BufferSize = 512;

  static const int kUtf16BufferSize = 128;

  int utf8_pos_;

  char utf8_buffer_[kUtf8BufferSize];

  uc16 utf16_buffer[kUtf16BufferSize];

};

CodeEventLogger::CodeEventLogger() : name_buffer_(new NameBuffer) { }

CodeEventLogger::~CodeEventLogger() { delete name_buffer_; }

void CodeEventLogger::CodeCreateEvent(Logger::LogEventsAndTags tag,

                                      Code* code,

                                      const char* comment) {

  name_buffer_->Init(tag);

  name_buffer_->AppendBytes(comment);

  LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());

}

void CodeEventLogger::CodeCreateEvent(Logger::LogEventsAndTags tag,

                                      Code* code,

                                      Name* name) {

  name_buffer_->Init(tag);

  name_buffer_->AppendName(name);

  LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());

}

void CodeEventLogger::CodeCreateEvent(Logger::LogEventsAndTags tag,

                                      Code* code,

                                      SharedFunctionInfo* shared,

                                      CompilationInfo* info,

                                      Name* name) {

  name_buffer_->Init(tag);

  name_buffer_->AppendBytes(ComputeMarker(code));

  name_buffer_->AppendName(name);

  LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());

}

void CodeEventLogger::CodeCreateEvent(Logger::LogEventsAndTags tag,

                                      Code* code,

                                      SharedFunctionInfo* shared,

                                      CompilationInfo* info,

                                      Name* source, int line, int column) {

  name_buffer_->Init(tag);

  name_buffer_->AppendBytes(ComputeMarker(code));

  name_buffer_->AppendString(shared->DebugName());

  name_buffer_->AppendByte(' ');

  if (source->IsString()) {

    name_buffer_->AppendString(String::cast(source));

  } else {

    name_buffer_->AppendBytes("symbol(hash ");

    name_buffer_->AppendHex(Name::cast(source)->Hash());

    name_buffer_->AppendByte(')');

  }

  name_buffer_->AppendByte(':');

  name_buffer_->AppendInt(line);

  LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());

}

void CodeEventLogger::CodeCreateEvent(Logger::LogEventsAndTags tag,

                                      Code* code,

                                      int args_count) {

  name_buffer_->Init(tag);

  name_buffer_->AppendInt(args_count);

  LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());

}

void CodeEventLogger::RegExpCodeCreateEvent(Code* code, String* source) {

  name_buffer_->Init(Logger::REG_EXP_TAG);

  name_buffer_->AppendString(source);

  LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());

}

// Low-level logging support.

#define LL_LOG(Call) if (ll_logger_) ll_logger_->Call;

class LowLevelLogger : public CodeEventLogger {

 public:

  explicit LowLevelLogger(const char* file_name);

  virtual ~LowLevelLogger();

  virtual void CodeMoveEvent(Address from, Address to);

  virtual void CodeDeleteEvent(Address from);

  virtual void SnapshotPositionEvent(Address addr, int pos);

  virtual void CodeMovingGCEvent();

 private:

  virtual void LogRecordedBuffer(Code* code,

                                 SharedFunctionInfo* shared,

                                 const char* name,

                                 int length);

  // Low-level profiling event structures.

  struct CodeCreateStruct {

    static const char kTag = 'C';

    int32_t name_size;

    Address code_address;

    int32_t code_size;

  };

  struct CodeMoveStruct {

    static const char kTag = 'M';

    Address from_address;

    Address to_address;

  };

  struct CodeDeleteStruct {

    static const char kTag = 'D';

    Address address;

  };

  struct SnapshotPositionStruct {

    static const char kTag = 'P';

    Address address;

    int32_t position;

  };

  static const char kCodeMovingGCTag = 'G';

  // Extension added to V8 log file name to get the low-level log name.

  static const char kLogExt[];

  // File buffer size of the low-level log. We don't use the default to

  // minimize the associated overhead.

  static const int kLogBufferSize = 2 * MB;

  void LogCodeInfo();

  void LogWriteBytes(const char* bytes, int size);

  template <typename T>

  void LogWriteStruct(const T& s) {

    char tag = T::kTag;

    LogWriteBytes(reinterpret_cast<const char*>(&tag), sizeof(tag));

    LogWriteBytes(reinterpret_cast<const char*>(&s), sizeof(s));

  }

  FILE* ll_output_handle_;

};

const char LowLevelLogger::kLogExt[] = ".ll";

LowLevelLogger::LowLevelLogger(const char* name)

    : ll_output_handle_(NULL) {

  // Open the low-level log file.

  size_t len = strlen(name);

  ScopedVector<char> ll_name(static_cast<int>(len + sizeof(kLogExt)));

  OS::MemCopy(ll_name.start(), name, len);

  OS::MemCopy(ll_name.start() + len, kLogExt, sizeof(kLogExt));

  ll_output_handle_ = OS::FOpen(ll_name.start(), OS::LogFileOpenMode);

  setvbuf(ll_output_handle_, NULL, _IOFBF, kLogBufferSize);

  LogCodeInfo();

}

LowLevelLogger::~LowLevelLogger() {

  fclose(ll_output_handle_);

  ll_output_handle_ = NULL;

}

void LowLevelLogger::LogCodeInfo() {

#if V8_TARGET_ARCH_IA32

  const char arch[] = "ia32";

#elif V8_TARGET_ARCH_X64

  const char arch[] = "x64";

#elif V8_TARGET_ARCH_ARM

  const char arch[] = "arm";

#elif V8_TARGET_ARCH_MIPS

  const char arch[] = "mips";

#else

  const char arch[] = "unknown";

#endif

  LogWriteBytes(arch, sizeof(arch));

}

void LowLevelLogger::LogRecordedBuffer(Code* code,

                                       SharedFunctionInfo*,

                                       const char* name,

                                       int length) {

  CodeCreateStruct event;

  event.name_size = length;

  event.code_address = code->instruction_start();

  ASSERT(event.code_address == code->address() + Code::kHeaderSize);

  event.code_size = code->instruction_size();

  LogWriteStruct(event);

  LogWriteBytes(name, length);

  LogWriteBytes(

      reinterpret_cast<const char*>(code->instruction_start()),

      code->instruction_size());

}

void LowLevelLogger::CodeMoveEvent(Address from, Address to) {

  CodeMoveStruct event;

  event.from_address = from + Code::kHeaderSize;

  event.to_address = to + Code::kHeaderSize;

  LogWriteStruct(event);

}

void LowLevelLogger::CodeDeleteEvent(Address from) {

  CodeDeleteStruct event;

  event.address = from + Code::kHeaderSize;

  LogWriteStruct(event);

}

void LowLevelLogger::SnapshotPositionEvent(Address addr, int pos) {

  SnapshotPositionStruct event;

  event.address = addr + Code::kHeaderSize;

  event.position = pos;

  LogWriteStruct(event);

}

void LowLevelLogger::LogWriteBytes(const char* bytes, int size) {

  size_t rv = fwrite(bytes, 1, size, ll_output_handle_);

  ASSERT(static_cast<size_t>(size) == rv);

  USE(rv);

}

void LowLevelLogger::CodeMovingGCEvent() {

  const char tag = kCodeMovingGCTag;

  LogWriteBytes(&tag, sizeof(tag));

}

#define JIT_LOG(Call) if (jit_logger_) jit_logger_->Call;

class JitLogger : public CodeEventLogger {

 public:

  explicit JitLogger(JitCodeEventHandler code_event_handler);

  virtual void CodeMoveEvent(Address from, Address to);

  virtual void CodeDeleteEvent(Address from);

  virtual void AddCodeLinePosInfoEvent(

      void* jit_handler_data,

      int pc_offset,

      int position,

      JitCodeEvent::PositionType position_type);

  void* StartCodePosInfoEvent();

  void EndCodePosInfoEvent(Code* code, void* jit_handler_data);

 private:

  virtual void LogRecordedBuffer(Code* code,

                                 SharedFunctionInfo* shared,

                                 const char* name,

                                 int length);

  JitCodeEventHandler code_event_handler_;

};

JitLogger::JitLogger(JitCodeEventHandler code_event_handler)

    : code_event_handler_(code_event_handler) {

}

void JitLogger::LogRecordedBuffer(Code* code,

                                  SharedFunctionInfo* shared,

                                  const char* name,

                                  int length) {

  JitCodeEvent event;

  memset(&event, 0, sizeof(event));

  event.type = JitCodeEvent::CODE_ADDED;

  event.code_start = code->instruction_start();

  event.code_len = code->instruction_size();

  Handle<Script> script_handle;

  if (shared && shared->script()->IsScript()) {

    script_handle = Handle<Script>(Script::cast(shared->script()));

  }

  event.script = ToApiHandle<v8::Script>(script_handle);

  event.name.str = name;

  event.name.len = length;

  code_event_handler_(&event);

}

void JitLogger::CodeMoveEvent(Address from, Address to) {

  Code* from_code = Code::cast(HeapObject::FromAddress(from));

  JitCodeEvent event;

  event.type = JitCodeEvent::CODE_MOVED;

  event.code_start = from_code->instruction_start();

  event.code_len = from_code->instruction_size();

  // Calculate the header size.

  const size_t header_size =

      from_code->instruction_start() - reinterpret_cast<byte*>(from_code);

  // Calculate the new start address of the instructions.

  event.new_code_start =

      reinterpret_cast<byte*>(HeapObject::FromAddress(to)) + header_size;

  code_event_handler_(&event);

}

void JitLogger::CodeDeleteEvent(Address from) {

  Code* from_code = Code::cast(HeapObject::FromAddress(from));

  JitCodeEvent event;

  event.type = JitCodeEvent::CODE_REMOVED;

  event.code_start = from_code->instruction_start();

  event.code_len = from_code->instruction_size();

  code_event_handler_(&event);

}

void JitLogger::AddCodeLinePosInfoEvent(

    void* jit_handler_data,

    int pc_offset,

    int position,

    JitCodeEvent::PositionType position_type) {

  JitCodeEvent event;

  memset(&event, 0, sizeof(event));

  event.type = JitCodeEvent::CODE_ADD_LINE_POS_INFO;

  event.user_data = jit_handler_data;

  event.line_info.offset = pc_offset;

  event.line_info.pos = position;

  event.line_info.position_type = position_type;

  code_event_handler_(&event);

}

void* JitLogger::StartCodePosInfoEvent() {

  JitCodeEvent event;

  memset(&event, 0, sizeof(event));

  event.type = JitCodeEvent::CODE_START_LINE_INFO_RECORDING;

  code_event_handler_(&event);

  return event.user_data;

}

void JitLogger::EndCodePosInfoEvent(Code* code, void* jit_handler_data) {

  JitCodeEvent event;

  memset(&event, 0, sizeof(event));

  event.type = JitCodeEvent::CODE_END_LINE_INFO_RECORDING;

  event.code_start = code->instruction_start();

  event.user_data = jit_handler_data;

  code_event_handler_(&event);

}

// The Profiler samples pc and sp values for the main thread.

// Each sample is appended to a circular buffer.

// An independent thread removes data and writes it to the log.

// This design minimizes the time spent in the sampler.

//

class Profiler: public Thread {

 public:

  explicit Profiler(Isolate* isolate);

  void Engage();

  void Disengage();

  // Inserts collected profiling data into buffer.

  void Insert(TickSample* sample) {

    if (paused_)

      return;

    if (Succ(head_) == tail_) {

      overflow_ = true;

    } else {

      buffer_[head_] = *sample;

      head_ = Succ(head_);

      buffer_semaphore_.Signal();  // Tell we have an element.

    }

  }

  virtual void Run();

  // Pause and Resume TickSample data collection.

  void pause() { paused_ = true; }

  void resume() { paused_ = false; }

 private:

  // Waits for a signal and removes profiling data.

  bool Remove(TickSample* sample) {

    buffer_semaphore_.Wait();  // Wait for an element.

    *sample = buffer_[tail_];

    bool result = overflow_;

    tail_ = Succ(tail_);

    overflow_ = false;

    return result;

  }

  // Returns the next index in the cyclic buffer.

  int Succ(int index) { return (index + 1) % kBufferSize; }

  Isolate* isolate_;

  // Cyclic buffer for communicating profiling samples

  // between the signal handler and the worker thread.

  static const int kBufferSize = 128;

  TickSample buffer_[kBufferSize];  // Buffer storage.

  int head_;  // Index to the buffer head.

  int tail_;  // Index to the buffer tail.

  bool overflow_;  // Tell whether a buffer overflow has occurred.

  // Sempahore used for buffer synchronization.

  Semaphore buffer_semaphore_;

  // Tells whether profiler is engaged, that is, processing thread is stated.

  bool engaged_;

  // Tells whether worker thread should continue running.

  bool running_;

  // Tells whether we are currently recording tick samples.

  bool paused_;

};

//

// Ticker used to provide ticks to the profiler and the sliding state

// window.

//

class Ticker: public Sampler {

 public:

  Ticker(Isolate* isolate, int interval):

      Sampler(isolate, interval),

      profiler_(NULL) {}

  ~Ticker() { if (IsActive()) Stop(); }

  virtual void Tick(TickSample* sample) {

    if (profiler_) profiler_->Insert(sample);

  }

  void SetProfiler(Profiler* profiler) {

    ASSERT(profiler_ == NULL);

    profiler_ = profiler;

    IncreaseProfilingDepth();

    if (!IsActive()) Start();

  }

  void ClearProfiler() {

    profiler_ = NULL;

    if (IsActive()) Stop();

    DecreaseProfilingDepth();

  }

 private:

  Profiler* profiler_;

};

//

// Profiler implementation.

//

Profiler::Profiler(Isolate* isolate)

    : Thread("v8:Profiler"),

      isolate_(isolate),

      head_(0),

      tail_(0),

      overflow_(false),

      buffer_semaphore_(0),

      engaged_(false),

      running_(false),

      paused_(false) {

}

void Profiler::Engage() {

  if (engaged_) return;

  engaged_ = true;

  OS::LogSharedLibraryAddresses(isolate_);

  // Start thread processing the profiler buffer.

  running_ = true;

  Start();

  // Register to get ticks.

  Logger* logger = isolate_->logger();

  logger->ticker_->SetProfiler(this);

  logger->ProfilerBeginEvent();

}

void Profiler::Disengage() {

  if (!engaged_) return;

  // Stop receiving ticks.

  isolate_->logger()->ticker_->ClearProfiler();

  // Terminate the worker thread by setting running_ to false,

  // inserting a fake element in the queue and then wait for

  // the thread to terminate.

  running_ = false;

  TickSample sample;

  // Reset 'paused_' flag, otherwise semaphore may not be signalled.

  resume();

  Insert(&sample);

  Join();

  LOG(isolate_, UncheckedStringEvent("profiler", "end"));

}

void Profiler::Run() {

  TickSample sample;

  bool overflow = Remove(&sample);

  while (running_) {

    LOG(isolate_, TickEvent(&sample, overflow));

    overflow = Remove(&sample);

  }

}

//

// Logger class implementation.

//

Logger::Logger(Isolate* isolate)

  : isolate_(isolate),

    ticker_(NULL),

    profiler_(NULL),

    log_events_(NULL),

    is_logging_(false),

    log_(new Log(this)),

    ll_logger_(NULL),

    jit_logger_(NULL),

    listeners_(5),

    is_initialized_(false) {

}

Logger::~Logger() {

  delete log_;

}

void Logger::addCodeEventListener(CodeEventListener* listener) {

  ASSERT(!hasCodeEventListener(listener));

  listeners_.Add(listener);

}

void Logger::removeCodeEventListener(CodeEventListener* listener) {

  ASSERT(hasCodeEventListener(listener));

  listeners_.RemoveElement(listener);

}

bool Logger::hasCodeEventListener(CodeEventListener* listener) {

  return listeners_.Contains(listener);

}

void Logger::ProfilerBeginEvent() {

  if (!log_->IsEnabled()) return;

  Log::MessageBuilder msg(log_);

  msg.Append("profiler,\"begin\",%d\n", kSamplingIntervalMs);

  msg.WriteToLogFile();

}

void Logger::StringEvent(const char* name, const char* value) {

  if (FLAG_log) UncheckedStringEvent(name, value);

}

void Logger::UncheckedStringEvent(const char* name, const char* value) {

  if (!log_->IsEnabled()) return;

  Log::MessageBuilder msg(log_);

  msg.Append("%s,\"%s\"\n", name, value);

  msg.WriteToLogFile();

}

void Logger::IntEvent(const char* name, int value) {

  if (FLAG_log) UncheckedIntEvent(name, value);

}

void Logger::IntPtrTEvent(const char* name, intptr_t value) {

  if (FLAG_log) UncheckedIntPtrTEvent(name, value);

}

void Logger::UncheckedIntEvent(const char* name, int value) {

  if (!log_->IsEnabled()) return;

  Log::MessageBuilder msg(log_);

  msg.Append("%s,%d\n", name, value);

  msg.WriteToLogFile();

}

void Logger::UncheckedIntPtrTEvent(const char* name, intptr_t value) {

  if (!log_->IsEnabled()) return;

  Log::MessageBuilder msg(log_);

  msg.Append("%s,%" V8_PTR_PREFIX "d\n", name, value);

  msg.WriteToLogFile();

}

void Logger::HandleEvent(const char* name, Object** location) {

  if (!log_->IsEnabled() || !FLAG_log_handles) return;

  Log::MessageBuilder msg(log_);

  msg.Append("%s,0x%" V8PRIxPTR "\n", name, location);

  msg.WriteToLogFile();

}

// ApiEvent is private so all the calls come from the Logger class.  It is the

// caller's responsibility to ensure that log is enabled and that

// FLAG_log_api is true.

void Logger::ApiEvent(const char* format, ...) {

  ASSERT(log_->IsEnabled() && FLAG_log_api);

  Log::MessageBuilder msg(log_);

  va_list ap;

  va_start(ap, format);

  msg.AppendVA(format, ap);

  va_end(ap);

  msg.WriteToLogFile();

}

void Logger::ApiNamedSecurityCheck(Object* key) {

  if (!log_->IsEnabled() || !FLAG_log_api) return;

  if (key->IsString()) {

    SmartArrayPointer<char> str =

        String::cast(key)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);

    ApiEvent("api,check-security,\"%s\"\n", *str);

  } else if (key->IsSymbol()) {

    Symbol* symbol = Symbol::cast(key);

    if (symbol->name()->IsUndefined()) {

      ApiEvent("api,check-security,symbol(hash %x)\n",

               Symbol::cast(key)->Hash());

    } else {

      SmartArrayPointer<char> str = String::cast(symbol->name())->ToCString(

          DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);

      ApiEvent("api,check-security,symbol(\"%s\" hash %x)\n",

               *str,

               Symbol::cast(key)->Hash());

    }

  } else if (key->IsUndefined()) {

    ApiEvent("api,check-security,undefined\n");

  } else {

    ApiEvent("api,check-security,['no-name']\n");

  }

}

void Logger::SharedLibraryEvent(const char* library_path,

                                uintptr_t start,

                                uintptr_t end) {

  if (!log_->IsEnabled() || !FLAG_prof) return;

  Log::MessageBuilder msg(log_);

  msg.Append("shared-library,\"%s\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR "\n",

             library_path,

             start,

             end);

  msg.WriteToLogFile();

}

void Logger::SharedLibraryEvent(const wchar_t* library_path,

                                uintptr_t start,

                                uintptr_t end) {

  if (!log_->IsEnabled() || !FLAG_prof) return;

  Log::MessageBuilder msg(log_);

  msg.Append("shared-library,\"%ls\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR "\n",

             library_path,

             start,

             end);

  msg.WriteToLogFile();

}

void Logger::CodeDeoptEvent(Code* code) {

  if (!log_->IsEnabled()) return;

  ASSERT(FLAG_log_internal_timer_events);

  Log::MessageBuilder msg(log_);

  int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());

  msg.Append("code-deopt,%ld,%d\n", since_epoch, code->CodeSize());

  msg.WriteToLogFile();

}

void Logger::TimerEvent(StartEnd se, const char* name) {

  if (!log_->IsEnabled()) return;

  ASSERT(FLAG_log_internal_timer_events);

  Log::MessageBuilder msg(log_);

  int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());

  const char* format = (se == START) ? "timer-event-start,\"%s\",%ld\n"

                                     : "timer-event-end,\"%s\",%ld\n";

  msg.Append(format, name, since_epoch);

  msg.WriteToLogFile();

}

void Logger::EnterExternal(Isolate* isolate) {

  LOG(isolate, TimerEvent(START, TimerEventScope::v8_external));

  ASSERT(isolate->current_vm_state() == JS);

  isolate->set_current_vm_state(EXTERNAL);

}

void Logger::LeaveExternal(Isolate* isolate) {

  LOG(isolate, TimerEvent(END, TimerEventScope::v8_external));

  ASSERT(isolate->current_vm_state() == EXTERNAL);

  isolate->set_current_vm_state(JS);

}

void Logger::TimerEventScope::LogTimerEvent(StartEnd se) {

  LOG(isolate_, TimerEvent(se, name_));

}

const char* Logger::TimerEventScope::v8_recompile_synchronous =

    "V8.RecompileSynchronous";

const char* Logger::TimerEventScope::v8_recompile_concurrent =

    "V8.RecompileConcurrent";

const char* Logger::TimerEventScope::v8_compile_full_code =

    "V8.CompileFullCode";

const char* Logger::TimerEventScope::v8_execute = "V8.Execute";

const char* Logger::TimerEventScope::v8_external = "V8.External";

void Logger::LogRegExpSource(Handle<JSRegExp> regexp) {

  // Prints "/" + re.source + "/" +

  //      (re.global?"g":"") + (re.ignorecase?"i":"") + (re.multiline?"m":"")

  Log::MessageBuilder msg(log_);

  Handle<Object> source = GetProperty(regexp, "source");

  if (!source->IsString()) {

    msg.Append("no source");

    return;

  }

  switch (regexp->TypeTag()) {

    case JSRegExp::ATOM:

      msg.Append('a');

      break;

    default:

      break;

  }

  msg.Append('/');

  msg.AppendDetailed(*Handle<String>::cast(source), false);

  msg.Append('/');

  // global flag

  Handle<Object> global = GetProperty(regexp, "global");

  if (global->IsTrue()) {

    msg.Append('g');

  }

  // ignorecase flag

  Handle<Object> ignorecase = GetProperty(regexp, "ignoreCase");

  if (ignorecase->IsTrue()) {

    msg.Append('i');

  }

  // multiline flag

  Handle<Object> multiline = GetProperty(regexp, "multiline");

  if (multiline->IsTrue()) {

    msg.Append('m');

  }

  msg.WriteToLogFile();

}

void Logger::RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache) {

  if (!log_->IsEnabled() || !FLAG_log_regexp) return;

  Log::MessageBuilder msg(log_);

  msg.Append("regexp-compile,");

  LogRegExpSource(regexp);

  msg.Append(in_cache ? ",hit\n" : ",miss\n");

  msg.WriteToLogFile();

}

void Logger::LogRuntime(Vector<const char> format,

                        JSArray* args) {

  if (!log_->IsEnabled() || !FLAG_log_runtime) return;

  HandleScope scope(isolate_);

  Log::MessageBuilder msg(log_);

  for (int i = 0; i < format.length(); i++) {

    char c = format[i];

    if (c == '%' && i <= format.length() - 2) {

      i++;

      ASSERT('0' <= format[i] && format[i] <= '9');

      MaybeObject* maybe = args->GetElement(isolate_, format[i] - '0');

      Object* obj;

      if (!maybe->ToObject(&obj)) {

        msg.Append("<exception>");

        continue;

      }

      i++;

      switch (format[i]) {

        case 's':

          msg.AppendDetailed(String::cast(obj), false);

          break;

        case 'S':

          msg.AppendDetailed(String::cast(obj), true);

          break;

        case 'r':

          Logger::LogRegExpSource(Handle<JSRegExp>(JSRegExp::cast(obj)));

          break;

        case 'x':

          msg.Append("0x%x", Smi::cast(obj)->value());

          break;

        case 'i':

          msg.Append("%i", Smi::cast(obj)->value());

          break;

        default:

          UNREACHABLE();

      }

    } else {

      msg.Append(c);

    }

  }

  msg.Append('\n');

  msg.WriteToLogFile();

}

void Logger::ApiIndexedSecurityCheck(uint32_t index) {

  if (!log_->IsEnabled() || !FLAG_log_api) return;

  ApiEvent("api,check-security,%u\n", index);

}

void Logger::ApiNamedPropertyAccess(const char* tag,

                                    JSObject* holder,

                                    Object* name) {

  ASSERT(name->IsName());

  if (!log_->IsEnabled() || !FLAG_log_api) return;

  String* class_name_obj = holder->class_name();

  SmartArrayPointer<char> class_name =

      class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);

  if (name->IsString()) {

    SmartArrayPointer<char> property_name =

        String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);

    ApiEvent("api,%s,\"%s\",\"%s\"\n", tag, *class_name, *property_name);

  } else {

    Symbol* symbol = Symbol::cast(name);

    uint32_t hash = symbol->Hash();

    if (symbol->name()->IsUndefined()) {

      ApiEvent("api,%s,\"%s\",symbol(hash %x)\n", tag, *class_name, hash);

    } else {

      SmartArrayPointer<char> str = String::cast(symbol->name())->ToCString(

          DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);

      ApiEvent("api,%s,\"%s\",symbol(\"%s\" hash %x)\n",

               tag, *class_name, *str, hash);

    }

  }

}

void Logger::ApiIndexedPropertyAccess(const char* tag,

                                      JSObject* holder,

                                      uint32_t index) {

  if (!log_->IsEnabled() || !FLAG_log_api) return;

  String* class_name_obj = holder->class_name();

  SmartArrayPointer<char> class_name =

      class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);

  ApiEvent("api,%s,\"%s\",%u\n", tag, *class_name, index);

}

void Logger::ApiObjectAccess(const char* tag, JSObject* object) {

  if (!log_->IsEnabled() || !FLAG_log_api) return;

  String* class_name_obj = object->class_name();

  SmartArrayPointer<char> class_name =

      class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);

  ApiEvent("api,%s,\"%s\"\n", tag, *class_name);

}

void Logger::ApiEntryCall(const char* name) {

  if (!log_->IsEnabled() || !FLAG_log_api) return;

  ApiEvent("api,%s\n", name);

}

void Logger::NewEvent(const char* name, void* object, size_t size) {

  if (!log_->IsEnabled() || !FLAG_log) return;

  Log::MessageBuilder msg(log_);

  msg.Append("new,%s,0x%" V8PRIxPTR ",%u\n", name, object,

             static_cast<unsigned int>(size));

  msg.WriteToLogFile();

}

void Logger::DeleteEvent(const char* name, void* object) {

  if (!log_->IsEnabled() || !FLAG_log) return;

  Log::MessageBuilder msg(log_);

  msg.Append("delete,%s,0x%" V8PRIxPTR "\n", name, object);

  msg.WriteToLogFile();

}

void Logger::NewEventStatic(const char* name, void* object, size_t size) {

  Isolate::Current()->logger()->NewEvent(name, object, size);

}

void Logger::DeleteEventStatic(const char* name, void* object) {

  Isolate::Current()->logger()->DeleteEvent(name, object);

}

void Logger::CallbackEventInternal(const char* prefix, Name* name,

                                   Address entry_point) {

  if (!FLAG_log_code || !log_->IsEnabled()) return;

  Log::MessageBuilder msg(log_);

  msg.Append("%s,%s,-2,",

             kLogEventsNames[CODE_CREATION_EVENT],

             kLogEventsNames[CALLBACK_TAG]);

  msg.AppendAddress(entry_point);

  if (name->IsString()) {

    SmartArrayPointer<char> str =

        String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);

    msg.Append(",1,\"%s%s\"", prefix, *str);

  } else {

    Symbol* symbol = Symbol::cast(name);

    if (symbol->name()->IsUndefined()) {

      msg.Append(",1,symbol(hash %x)", prefix, symbol->Hash());

    } else {

      SmartArrayPointer<char> str = String::cast(symbol->name())->ToCString(

          DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);

      msg.Append(",1,symbol(\"%s\" hash %x)", prefix, *str, symbol->Hash());

    }

  }

  msg.Append('\n');

  msg.WriteToLogFile();

}

void Logger::CallbackEvent(Name* name, Address entry_point) {

  PROFILER_LOG(CallbackEvent(name, entry_point));

  CallbackEventInternal("", name, entry_point);

}

void Logger::GetterCallbackEvent(Name* name, Address entry_point) {

  PROFILER_LOG(GetterCallbackEvent(name, entry_point));

  CallbackEventInternal("get ", name, entry_point);

}

void Logger::SetterCallbackEvent(Name* name, Address entry_point) {

  PROFILER_LOG(SetterCallbackEvent(name, entry_point));

  CallbackEventInternal("set ", name, entry_point);

}

static void AppendCodeCreateHeader(Log::MessageBuilder* msg,

                                   Logger::LogEventsAndTags tag,

                                   Code* code) {

  ASSERT(msg);

  msg->Append("%s,%s,%d,",

              kLogEventsNames[Logger::CODE_CREATION_EVENT],

              kLogEventsNames[tag],

              code->kind());

  msg->AppendAddress(code->address());

  msg->Append(",%d,", code->ExecutableSize());

}

void Logger::CodeCreateEvent(LogEventsAndTags tag,

                             Code* code,

                             const char* comment) {

  PROFILER_LOG(CodeCreateEvent(tag, code, comment));

  if (!is_logging_code_events()) return;

  CALL_LISTENERS(CodeCreateEvent(tag, code, comment));

  if (!FLAG_log_code || !log_->IsEnabled()) return;

  Log::MessageBuilder msg(log_);

  AppendCodeCreateHeader(&msg, tag, code);

  msg.AppendDoubleQuotedString(comment);

  msg.Append('\n');

  msg.WriteToLogFile();

}

void Logger::CodeCreateEvent(LogEventsAndTags tag,

                             Code* code,

                             Name* name) {

  PROFILER_LOG(CodeCreateEvent(tag, code, name));

  if (!is_logging_code_events()) return;

  CALL_LISTENERS(CodeCreateEvent(tag, code, name));

  if (!FLAG_log_code || !log_->IsEnabled()) return;

  Log::MessageBuilder msg(log_);

  AppendCodeCreateHeader(&msg, tag, code);

  if (name->IsString()) {

    msg.Append('"');

    msg.AppendDetailed(String::cast(name), false);

    msg.Append('"');

  } else {

    msg.AppendSymbolName(Symbol::cast(name));

  }

  msg.Append('\n');

  msg.WriteToLogFile();

}

void Logger::CodeCreateEvent(LogEventsAndTags tag,

                             Code* code,

                             SharedFunctionInfo* shared,

                             CompilationInfo* info,

                             Name* name) {

  PROFILER_LOG(CodeCreateEvent(tag, code, shared, info, name));

  if (!is_logging_code_events()) return;

  CALL_LISTENERS(CodeCreateEvent(tag, code, shared, info, name));

  if (!FLAG_log_code || !log_->IsEnabled()) return;

  if (code == isolate_->builtins()->builtin(

      Builtins::kLazyCompile))

    return;

  Log::MessageBuilder msg(log_);

  AppendCodeCreateHeader(&msg, tag, code);

  if (name->IsString()) {

    SmartArrayPointer<char> str =

        String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);

    msg.Append("\"%s\"", *str);

  } else {

    msg.AppendSymbolName(Symbol::cast(name));

  }

  msg.Append(',');

  msg.AppendAddress(shared->address());

  msg.Append(",%s", ComputeMarker(code));

  msg.Append('\n');

  msg.WriteToLogFile();

}

// Although, it is possible to extract source and line from

// the SharedFunctionInfo object, we left it to caller

// to leave logging functions free from heap allocations.

void Logger::CodeCreateEvent(LogEventsAndTags tag,

                             Code* code,

                             SharedFunctionInfo* shared,

                             CompilationInfo* info,

                             Name* source, int line, int column) {

  PROFILER_LOG(CodeCreateEvent(tag, code, shared, info, source, line, column));

  if (!is_logging_code_events()) return;

  CALL_LISTENERS(CodeCreateEvent(tag, code, shared, info, source, line,

                                 column));

  if (!FLAG_log_code || !log_->IsEnabled()) return;

  Log::MessageBuilder msg(log_);

  AppendCodeCreateHeader(&msg, tag, code);

  SmartArrayPointer<char> name =

      shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);

  msg.Append("\"%s ", *name);

  if (source->IsString()) {

    SmartArrayPointer<char> sourcestr =

       String::cast(source)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);

    msg.Append("%s", *sourcestr);

  } else {

    msg.AppendSymbolName(Symbol::cast(source));

  }

  msg.Append(":%d:%d\",", line, column);

  msg.AppendAddress(shared->address());

  msg.Append(",%s", ComputeMarker(code));

  msg.Append('\n');

  msg.WriteToLogFile();

}

void Logger::CodeCreateEvent(LogEventsAndTags tag,

                             Code* code,

                             int args_count) {

  PROFILER_LOG(CodeCreateEvent(tag, code, args_count));

  if (!is_logging_code_events()) return;

  CALL_LISTENERS(CodeCreateEvent(tag, code, args_count));

  if (!FLAG_log_code || !log_->IsEnabled()) return;

  Log::MessageBuilder msg(log_);

  AppendCodeCreateHeader(&msg, tag, code);

  msg.Append("\"args_count: %d\"", args_count);

  msg.Append('\n');

  msg.WriteToLogFile();

}

void Logger::CodeMovingGCEvent() {

  PROFILER_LOG(CodeMovingGCEvent());

  if (!is_logging_code_events()) return;

  if (!log_->IsEnabled() || !FLAG_ll_prof) return;

  CALL_LISTENERS(CodeMovingGCEvent());

  OS::SignalCodeMovingGC();

}

void Logger::RegExpCodeCreateEvent(Code* code, String* source) {

  PROFILER_LOG(RegExpCodeCreateEvent(code, source));

  if (!is_logging_code_events()) return;

  CALL_LISTENERS(RegExpCodeCreateEvent(code, source));

  if (!FLAG_log_code || !log_->IsEnabled()) return;

  Log::MessageBuilder msg(log_);

  AppendCodeCreateHeader(&msg, REG_EXP_TAG, code);

  msg.Append('"');

  msg.AppendDetailed(source, false);

  msg.Append('"');

  msg.Append('\n');

  msg.WriteToLogFile();

}

void Logger::CodeMoveEvent(Address from, Address to) {

  PROFILER_LOG(CodeMoveEvent(from, to));

  if (!is_logging_code_events()) return;

  CALL_LISTENERS(CodeMoveEvent(from, to));

  MoveEventInternal(CODE_MOVE_EVENT, from, to);

}

void Logger::CodeDeleteEvent(Address from) {

  PROFILER_LOG(CodeDeleteEvent(from));

  if (!is_logging_code_events()) return;

  CALL_LISTENERS(CodeDeleteEvent(from));

  if (!FLAG_log_code || !log_->IsEnabled()) return;

  Log::MessageBuilder msg(log_);

  msg.Append("%s,", kLogEventsNames[CODE_DELETE_EVENT]);

  msg.AppendAddress(from);

  msg.Append('\n');

  msg.WriteToLogFile();

}

void Logger::CodeLinePosInfoAddPositionEvent(void* jit_handler_data,

                                     int pc_offset,

                                     int position) {

  JIT_LOG(AddCodeLinePosInfoEvent(jit_handler_data,

                                  pc_offset,

                                  position,

                                  JitCodeEvent::POSITION));

}