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