Home | History | Annotate | Download | only in src 
      1 // Copyright 2009 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 "global-handles.h"
     34 #include "log.h"
     35 #include "macro-assembler.h"
     36 #include "serialize.h"
     37 #include "string-stream.h"
     38 
     39 namespace v8 {
     40 namespace internal {
     41 
     42 #ifdef ENABLE_LOGGING_AND_PROFILING
     43 
     44 //
     45 // Sliding state window.  Updates counters to keep track of the last
     46 // window of kBufferSize states.  This is useful to track where we
     47 // spent our time.
     48 //
     49 class SlidingStateWindow {
     50  public:
     51   SlidingStateWindow();
     52   ~SlidingStateWindow();
     53   void AddState(StateTag state);
     54 
     55  private:
     56   static const int kBufferSize = 256;
     57   int current_index_;
     58   bool is_full_;
     59   byte buffer_[kBufferSize];
     60 
     61 
     62   void IncrementStateCounter(StateTag state) {
     63     Counters::state_counters[state].Increment();
     64   }
     65 
     66 
     67   void DecrementStateCounter(StateTag state) {
     68     Counters::state_counters[state].Decrement();
     69   }
     70 };
     71 
     72 
     73 //
     74 // The Profiler samples pc and sp values for the main thread.
     75 // Each sample is appended to a circular buffer.
     76 // An independent thread removes data and writes it to the log.
     77 // This design minimizes the time spent in the sampler.
     78 //
     79 class Profiler: public Thread {
     80  public:
     81   Profiler();
     82   void Engage();
     83   void Disengage();
     84 
     85   // Inserts collected profiling data into buffer.
     86   void Insert(TickSample* sample) {
     87     if (paused_)
     88       return;
     89 
     90     if (Succ(head_) == tail_) {
     91       overflow_ = true;
     92     } else {
     93       buffer_[head_] = *sample;
     94       head_ = Succ(head_);
     95       buffer_semaphore_->Signal();  // Tell we have an element.
     96     }
     97   }
     98 
     99   // Waits for a signal and removes profiling data.
    100   bool Remove(TickSample* sample) {
    101     buffer_semaphore_->Wait();  // Wait for an element.
    102     *sample = buffer_[tail_];
    103     bool result = overflow_;
    104     tail_ = Succ(tail_);
    105     overflow_ = false;
    106     return result;
    107   }
    108 
    109   void Run();
    110 
    111   // Pause and Resume TickSample data collection.
    112   static bool paused() { return paused_; }
    113   static void pause() { paused_ = true; }
    114   static void resume() { paused_ = false; }
    115 
    116  private:
    117   // Returns the next index in the cyclic buffer.
    118   int Succ(int index) { return (index + 1) % kBufferSize; }
    119 
    120   // Cyclic buffer for communicating profiling samples
    121   // between the signal handler and the worker thread.
    122   static const int kBufferSize = 128;
    123   TickSample buffer_[kBufferSize];  // Buffer storage.
    124   int head_;  // Index to the buffer head.
    125   int tail_;  // Index to the buffer tail.
    126   bool overflow_;  // Tell whether a buffer overflow has occurred.
    127   Semaphore* buffer_semaphore_;  // Sempahore used for buffer synchronization.
    128 
    129   // Tells whether profiler is engaged, that is, processing thread is stated.
    130   bool engaged_;
    131 
    132   // Tells whether worker thread should continue running.
    133   bool running_;
    134 
    135   // Tells whether we are currently recording tick samples.
    136   static bool paused_;
    137 };
    138 
    139 bool Profiler::paused_ = false;
    140 
    141 
    142 //
    143 // StackTracer implementation
    144 //
    145 void StackTracer::Trace(TickSample* sample) {
    146   if (sample->state == GC) {
    147     sample->frames_count = 0;
    148     return;
    149   }
    150 
    151   const Address js_entry_sp = Top::js_entry_sp(Top::GetCurrentThread());
    152   if (js_entry_sp == 0) {
    153     // Not executing JS now.
    154     sample->frames_count = 0;
    155     return;
    156   }
    157 
    158   const Address functionAddr =
    159       sample->fp + JavaScriptFrameConstants::kFunctionOffset;
    160   if (SafeStackFrameIterator::IsWithinBounds(sample->sp, js_entry_sp,
    161                                              functionAddr)) {
    162     sample->function = Memory::Address_at(functionAddr) - kHeapObjectTag;
    163   }
    164 
    165   int i = 0;
    166   const Address callback = Logger::current_state_ != NULL ?
    167       Logger::current_state_->external_callback() : NULL;
    168   if (callback != NULL) {
    169     sample->stack[i++] = callback;
    170   }
    171 
    172   SafeStackTraceFrameIterator it(sample->fp, sample->sp,
    173                                  sample->sp, js_entry_sp);
    174   while (!it.done() && i < TickSample::kMaxFramesCount) {
    175     sample->stack[i++] = it.frame()->pc();
    176     it.Advance();
    177   }
    178   sample->frames_count = i;
    179 }
    180 
    181 
    182 //
    183 // Ticker used to provide ticks to the profiler and the sliding state
    184 // window.
    185 //
    186 class Ticker: public Sampler {
    187  public:
    188   explicit Ticker(int interval):
    189       Sampler(interval, FLAG_prof), window_(NULL), profiler_(NULL) {}
    190 
    191   ~Ticker() { if (IsActive()) Stop(); }
    192 
    193   void SampleStack(TickSample* sample) {
    194     StackTracer::Trace(sample);
    195   }
    196 
    197   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()) Stop();
    210   }
    211 
    212   void SetProfiler(Profiler* profiler) {
    213     profiler_ = profiler;
    214     if (!FLAG_prof_lazy && !IsActive()) Start();
    215   }
    216 
    217   void ClearProfiler() {
    218     profiler_ = NULL;
    219     if (!window_ && IsActive()) Stop();
    220   }
    221 
    222  private:
    223   SlidingStateWindow* window_;
    224   Profiler* profiler_;
    225 };
    226 
    227 
    228 //
    229 // SlidingStateWindow implementation.
    230 //
    231 SlidingStateWindow::SlidingStateWindow(): current_index_(0), is_full_(false) {
    232   for (int i = 0; i < kBufferSize; i++) {
    233     buffer_[i] = static_cast<byte>(OTHER);
    234   }
    235   Logger::ticker_->SetWindow(this);
    236 }
    237 
    238 
    239 SlidingStateWindow::~SlidingStateWindow() {
    240   Logger::ticker_->ClearWindow();
    241 }
    242 
    243 
    244 void SlidingStateWindow::AddState(StateTag state) {
    245   if (is_full_) {
    246     DecrementStateCounter(static_cast<StateTag>(buffer_[current_index_]));
    247   } else if (current_index_ == kBufferSize - 1) {
    248     is_full_ = true;
    249   }
    250   buffer_[current_index_] = static_cast<byte>(state);
    251   IncrementStateCounter(state);
    252   ASSERT(IsPowerOf2(kBufferSize));
    253   current_index_ = (current_index_ + 1) & (kBufferSize - 1);
    254 }
    255 
    256 
    257 //
    258 // Profiler implementation.
    259 //
    260 Profiler::Profiler()
    261     : head_(0),
    262       tail_(0),
    263       overflow_(false),
    264       buffer_semaphore_(OS::CreateSemaphore(0)),
    265       engaged_(false),
    266       running_(false) {
    267 }
    268 
    269 
    270 void Profiler::Engage() {
    271   if (engaged_) return;
    272   engaged_ = true;
    273 
    274   // TODO(mnaganov): This is actually "Chromium" mode. Flags need to be revised.
    275   // http://code.google.com/p/v8/issues/detail?id=487
    276   if (!FLAG_prof_lazy) {
    277     OS::LogSharedLibraryAddresses();
    278   }
    279 
    280   // Start thread processing the profiler buffer.
    281   running_ = true;
    282   Start();
    283 
    284   // Register to get ticks.
    285   Logger::ticker_->SetProfiler(this);
    286 
    287   Logger::ProfilerBeginEvent();
    288   Logger::LogAliases();
    289 }
    290 
    291 
    292 void Profiler::Disengage() {
    293   if (!engaged_) return;
    294 
    295   // Stop receiving ticks.
    296   Logger::ticker_->ClearProfiler();
    297 
    298   // Terminate the worker thread by setting running_ to false,
    299   // inserting a fake element in the queue and then wait for
    300   // the thread to terminate.
    301   running_ = false;
    302   TickSample sample;
    303   // Reset 'paused_' flag, otherwise semaphore may not be signalled.
    304   resume();
    305   Insert(&sample);
    306   Join();
    307 
    308   LOG(UncheckedStringEvent("profiler", "end"));
    309 }
    310 
    311 
    312 void Profiler::Run() {
    313   TickSample sample;
    314   bool overflow = Logger::profiler_->Remove(&sample);
    315   while (running_) {
    316     LOG(TickEvent(&sample, overflow));
    317     overflow = Logger::profiler_->Remove(&sample);
    318   }
    319 }
    320 
    321 
    322 //
    323 // Logger class implementation.
    324 //
    325 Ticker* Logger::ticker_ = NULL;
    326 Profiler* Logger::profiler_ = NULL;
    327 VMState* Logger::current_state_ = NULL;
    328 VMState Logger::bottom_state_(EXTERNAL);
    329 SlidingStateWindow* Logger::sliding_state_window_ = NULL;
    330 const char** Logger::log_events_ = NULL;
    331 CompressionHelper* Logger::compression_helper_ = NULL;
    332 bool Logger::is_logging_ = false;
    333 int Logger::cpu_profiler_nesting_ = 0;
    334 int Logger::heap_profiler_nesting_ = 0;
    335 
    336 #define DECLARE_LONG_EVENT(ignore1, long_name, ignore2) long_name,
    337 const char* kLongLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = {
    338   LOG_EVENTS_AND_TAGS_LIST(DECLARE_LONG_EVENT)
    339 };
    340 #undef DECLARE_LONG_EVENT
    341 
    342 #define DECLARE_SHORT_EVENT(ignore1, ignore2, short_name) short_name,
    343 const char* kCompressedLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = {
    344   LOG_EVENTS_AND_TAGS_LIST(DECLARE_SHORT_EVENT)
    345 };
    346 #undef DECLARE_SHORT_EVENT
    347 
    348 
    349 void Logger::ProfilerBeginEvent() {
    350   if (!Log::IsEnabled()) return;
    351   LogMessageBuilder msg;
    352   msg.Append("profiler,\"begin\",%d\n", kSamplingIntervalMs);
    353   if (FLAG_compress_log) {
    354     msg.Append("profiler,\"compression\",%d\n", kCompressionWindowSize);
    355   }
    356   msg.WriteToLogFile();
    357 }
    358 
    359 
    360 void Logger::LogAliases() {
    361   if (!Log::IsEnabled() || !FLAG_compress_log) return;
    362   LogMessageBuilder msg;
    363   for (int i = 0; i < NUMBER_OF_LOG_EVENTS; ++i) {
    364     msg.Append("alias,%s,%s\n",
    365                kCompressedLogEventsNames[i], kLongLogEventsNames[i]);
    366   }
    367   msg.WriteToLogFile();
    368 }
    369 
    370 #endif  // ENABLE_LOGGING_AND_PROFILING
    371 
    372 
    373 void Logger::StringEvent(const char* name, const char* value) {
    374 #ifdef ENABLE_LOGGING_AND_PROFILING
    375   if (FLAG_log) UncheckedStringEvent(name, value);
    376 #endif
    377 }
    378 
    379 
    380 #ifdef ENABLE_LOGGING_AND_PROFILING
    381 void Logger::UncheckedStringEvent(const char* name, const char* value) {
    382   if (!Log::IsEnabled()) return;
    383   LogMessageBuilder msg;
    384   msg.Append("%s,\"%s\"\n", name, value);
    385   msg.WriteToLogFile();
    386 }
    387 #endif
    388 
    389 
    390 void Logger::IntEvent(const char* name, int value) {
    391 #ifdef ENABLE_LOGGING_AND_PROFILING
    392   if (!Log::IsEnabled() || !FLAG_log) return;
    393   LogMessageBuilder msg;
    394   msg.Append("%s,%d\n", name, value);
    395   msg.WriteToLogFile();
    396 #endif
    397 }
    398 
    399 
    400 void Logger::HandleEvent(const char* name, Object** location) {
    401 #ifdef ENABLE_LOGGING_AND_PROFILING
    402   if (!Log::IsEnabled() || !FLAG_log_handles) return;
    403   LogMessageBuilder msg;
    404   msg.Append("%s,0x%" V8PRIxPTR "\n", name, location);
    405   msg.WriteToLogFile();
    406 #endif
    407 }
    408 
    409 
    410 #ifdef ENABLE_LOGGING_AND_PROFILING
    411 // ApiEvent is private so all the calls come from the Logger class.  It is the
    412 // caller's responsibility to ensure that log is enabled and that
    413 // FLAG_log_api is true.
    414 void Logger::ApiEvent(const char* format, ...) {
    415   ASSERT(Log::IsEnabled() && FLAG_log_api);
    416   LogMessageBuilder msg;
    417   va_list ap;
    418   va_start(ap, format);
    419   msg.AppendVA(format, ap);
    420   va_end(ap);
    421   msg.WriteToLogFile();
    422 }
    423 #endif
    424 
    425 
    426 void Logger::ApiNamedSecurityCheck(Object* key) {
    427 #ifdef ENABLE_LOGGING_AND_PROFILING
    428   if (!Log::IsEnabled() || !FLAG_log_api) return;
    429   if (key->IsString()) {
    430     SmartPointer<char> str =
    431         String::cast(key)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    432     ApiEvent("api,check-security,\"%s\"\n", *str);
    433   } else if (key->IsUndefined()) {
    434     ApiEvent("api,check-security,undefined\n");
    435   } else {
    436     ApiEvent("api,check-security,['no-name']\n");
    437   }
    438 #endif
    439 }
    440 
    441 
    442 void Logger::SharedLibraryEvent(const char* library_path,
    443                                 uintptr_t start,
    444                                 uintptr_t end) {
    445 #ifdef ENABLE_LOGGING_AND_PROFILING
    446   if (!Log::IsEnabled() || !FLAG_prof) return;
    447   LogMessageBuilder msg;
    448   msg.Append("shared-library,\"%s\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR "\n",
    449              library_path,
    450              start,
    451              end);
    452   msg.WriteToLogFile();
    453 #endif
    454 }
    455 
    456 
    457 void Logger::SharedLibraryEvent(const wchar_t* library_path,
    458                                 uintptr_t start,
    459                                 uintptr_t end) {
    460 #ifdef ENABLE_LOGGING_AND_PROFILING
    461   if (!Log::IsEnabled() || !FLAG_prof) return;
    462   LogMessageBuilder msg;
    463   msg.Append("shared-library,\"%ls\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR "\n",
    464              library_path,
    465              start,
    466              end);
    467   msg.WriteToLogFile();
    468 #endif
    469 }
    470 
    471 
    472 #ifdef ENABLE_LOGGING_AND_PROFILING
    473 void Logger::LogRegExpSource(Handle<JSRegExp> regexp) {
    474   // Prints "/" + re.source + "/" +
    475   //      (re.global?"g":"") + (re.ignorecase?"i":"") + (re.multiline?"m":"")
    476   LogMessageBuilder msg;
    477 
    478   Handle<Object> source = GetProperty(regexp, "source");
    479   if (!source->IsString()) {
    480     msg.Append("no source");
    481     return;
    482   }
    483 
    484   switch (regexp->TypeTag()) {
    485     case JSRegExp::ATOM:
    486       msg.Append('a');
    487       break;
    488     default:
    489       break;
    490   }
    491   msg.Append('/');
    492   msg.AppendDetailed(*Handle<String>::cast(source), false);
    493   msg.Append('/');
    494 
    495   // global flag
    496   Handle<Object> global = GetProperty(regexp, "global");
    497   if (global->IsTrue()) {
    498     msg.Append('g');
    499   }
    500   // ignorecase flag
    501   Handle<Object> ignorecase = GetProperty(regexp, "ignoreCase");
    502   if (ignorecase->IsTrue()) {
    503     msg.Append('i');
    504   }
    505   // multiline flag
    506   Handle<Object> multiline = GetProperty(regexp, "multiline");
    507   if (multiline->IsTrue()) {
    508     msg.Append('m');
    509   }
    510 
    511   msg.WriteToLogFile();
    512 }
    513 #endif  // ENABLE_LOGGING_AND_PROFILING
    514 
    515 
    516 void Logger::RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache) {
    517 #ifdef ENABLE_LOGGING_AND_PROFILING
    518   if (!Log::IsEnabled() || !FLAG_log_regexp) return;
    519   LogMessageBuilder msg;
    520   msg.Append("regexp-compile,");
    521   LogRegExpSource(regexp);
    522   msg.Append(in_cache ? ",hit\n" : ",miss\n");
    523   msg.WriteToLogFile();
    524 #endif
    525 }
    526 
    527 
    528 void Logger::LogRuntime(Vector<const char> format, JSArray* args) {
    529 #ifdef ENABLE_LOGGING_AND_PROFILING
    530   if (!Log::IsEnabled() || !FLAG_log_runtime) return;
    531   HandleScope scope;
    532   LogMessageBuilder msg;
    533   for (int i = 0; i < format.length(); i++) {
    534     char c = format[i];
    535     if (c == '%' && i <= format.length() - 2) {
    536       i++;
    537       ASSERT('0' <= format[i] && format[i] <= '9');
    538       Object* obj = args->GetElement(format[i] - '0');
    539       i++;
    540       switch (format[i]) {
    541         case 's':
    542           msg.AppendDetailed(String::cast(obj), false);
    543           break;
    544         case 'S':
    545           msg.AppendDetailed(String::cast(obj), true);
    546           break;
    547         case 'r':
    548           Logger::LogRegExpSource(Handle<JSRegExp>(JSRegExp::cast(obj)));
    549           break;
    550         case 'x':
    551           msg.Append("0x%x", Smi::cast(obj)->value());
    552           break;
    553         case 'i':
    554           msg.Append("%i", Smi::cast(obj)->value());
    555           break;
    556         default:
    557           UNREACHABLE();
    558       }
    559     } else {
    560       msg.Append(c);
    561     }
    562   }
    563   msg.Append('\n');
    564   msg.WriteToLogFile();
    565 #endif
    566 }
    567 
    568 
    569 void Logger::ApiIndexedSecurityCheck(uint32_t index) {
    570 #ifdef ENABLE_LOGGING_AND_PROFILING
    571   if (!Log::IsEnabled() || !FLAG_log_api) return;
    572   ApiEvent("api,check-security,%u\n", index);
    573 #endif
    574 }
    575 
    576 
    577 void Logger::ApiNamedPropertyAccess(const char* tag,
    578                                     JSObject* holder,
    579                                     Object* name) {
    580 #ifdef ENABLE_LOGGING_AND_PROFILING
    581   ASSERT(name->IsString());
    582   if (!Log::IsEnabled() || !FLAG_log_api) return;
    583   String* class_name_obj = holder->class_name();
    584   SmartPointer<char> class_name =
    585       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    586   SmartPointer<char> property_name =
    587       String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    588   Logger::ApiEvent("api,%s,\"%s\",\"%s\"\n", tag, *class_name, *property_name);
    589 #endif
    590 }
    591 
    592 void Logger::ApiIndexedPropertyAccess(const char* tag,
    593                                       JSObject* holder,
    594                                       uint32_t index) {
    595 #ifdef ENABLE_LOGGING_AND_PROFILING
    596   if (!Log::IsEnabled() || !FLAG_log_api) return;
    597   String* class_name_obj = holder->class_name();
    598   SmartPointer<char> class_name =
    599       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    600   Logger::ApiEvent("api,%s,\"%s\",%u\n", tag, *class_name, index);
    601 #endif
    602 }
    603 
    604 void Logger::ApiObjectAccess(const char* tag, JSObject* object) {
    605 #ifdef ENABLE_LOGGING_AND_PROFILING
    606   if (!Log::IsEnabled() || !FLAG_log_api) return;
    607   String* class_name_obj = object->class_name();
    608   SmartPointer<char> class_name =
    609       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    610   Logger::ApiEvent("api,%s,\"%s\"\n", tag, *class_name);
    611 #endif
    612 }
    613 
    614 
    615 void Logger::ApiEntryCall(const char* name) {
    616 #ifdef ENABLE_LOGGING_AND_PROFILING
    617   if (!Log::IsEnabled() || !FLAG_log_api) return;
    618   Logger::ApiEvent("api,%s\n", name);
    619 #endif
    620 }
    621 
    622 
    623 void Logger::NewEvent(const char* name, void* object, size_t size) {
    624 #ifdef ENABLE_LOGGING_AND_PROFILING
    625   if (!Log::IsEnabled() || !FLAG_log) return;
    626   LogMessageBuilder msg;
    627   msg.Append("new,%s,0x%" V8PRIxPTR ",%u\n", name, object,
    628              static_cast<unsigned int>(size));
    629   msg.WriteToLogFile();
    630 #endif
    631 }
    632 
    633 
    634 void Logger::DeleteEvent(const char* name, void* object) {
    635 #ifdef ENABLE_LOGGING_AND_PROFILING
    636   if (!Log::IsEnabled() || !FLAG_log) return;
    637   LogMessageBuilder msg;
    638   msg.Append("delete,%s,0x%" V8PRIxPTR "\n", name, object);
    639   msg.WriteToLogFile();
    640 #endif
    641 }
    642 
    643 
    644 #ifdef ENABLE_LOGGING_AND_PROFILING
    645 
    646 // A class that contains all common code dealing with record compression.
    647 class CompressionHelper {
    648  public:
    649   explicit CompressionHelper(int window_size)
    650       : compressor_(window_size), repeat_count_(0) { }
    651 
    652   // Handles storing message in compressor, retrieving the previous one and
    653   // prefixing it with repeat count, if needed.
    654   // Returns true if message needs to be written to log.
    655   bool HandleMessage(LogMessageBuilder* msg) {
    656     if (!msg->StoreInCompressor(&compressor_)) {
    657       // Current message repeats the previous one, don't write it.
    658       ++repeat_count_;
    659       return false;
    660     }
    661     if (repeat_count_ == 0) {
    662       return msg->RetrieveCompressedPrevious(&compressor_);
    663     }
    664     OS::SNPrintF(prefix_, "%s,%d,",
    665                  Logger::log_events_[Logger::REPEAT_META_EVENT],
    666                  repeat_count_ + 1);
    667     repeat_count_ = 0;
    668     return msg->RetrieveCompressedPrevious(&compressor_, prefix_.start());
    669   }
    670 
    671  private:
    672   LogRecordCompressor compressor_;
    673   int repeat_count_;
    674   EmbeddedVector<char, 20> prefix_;
    675 };
    676 
    677 #endif  // ENABLE_LOGGING_AND_PROFILING
    678 
    679 
    680 #ifdef ENABLE_LOGGING_AND_PROFILING
    681 void Logger::CallbackEventInternal(const char* prefix, const char* name,
    682                                    Address entry_point) {
    683   if (!Log::IsEnabled() || !FLAG_log_code) return;
    684   LogMessageBuilder msg;
    685   msg.Append("%s,%s,",
    686              log_events_[CODE_CREATION_EVENT], log_events_[CALLBACK_TAG]);
    687   msg.AppendAddress(entry_point);
    688   msg.Append(",1,\"%s%s\"", prefix, name);
    689   if (FLAG_compress_log) {
    690     ASSERT(compression_helper_ != NULL);
    691     if (!compression_helper_->HandleMessage(&msg)) return;
    692   }
    693   msg.Append('\n');
    694   msg.WriteToLogFile();
    695 }
    696 #endif
    697 
    698 
    699 void Logger::CallbackEvent(String* name, Address entry_point) {
    700 #ifdef ENABLE_LOGGING_AND_PROFILING
    701   if (!Log::IsEnabled() || !FLAG_log_code) return;
    702   SmartPointer<char> str =
    703       name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    704   CallbackEventInternal("", *str, entry_point);
    705 #endif
    706 }
    707 
    708 
    709 void Logger::GetterCallbackEvent(String* name, Address entry_point) {
    710 #ifdef ENABLE_LOGGING_AND_PROFILING
    711   if (!Log::IsEnabled() || !FLAG_log_code) return;
    712   SmartPointer<char> str =
    713       name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    714   CallbackEventInternal("get ", *str, entry_point);
    715 #endif
    716 }
    717 
    718 
    719 void Logger::SetterCallbackEvent(String* name, Address entry_point) {
    720 #ifdef ENABLE_LOGGING_AND_PROFILING
    721   if (!Log::IsEnabled() || !FLAG_log_code) return;
    722   SmartPointer<char> str =
    723       name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    724   CallbackEventInternal("set ", *str, entry_point);
    725 #endif
    726 }
    727 
    728 
    729 void Logger::CodeCreateEvent(LogEventsAndTags tag,
    730                              Code* code,
    731                              const char* comment) {
    732 #ifdef ENABLE_LOGGING_AND_PROFILING
    733   if (!Log::IsEnabled() || !FLAG_log_code) return;
    734   LogMessageBuilder msg;
    735   msg.Append("%s,%s,", log_events_[CODE_CREATION_EVENT], log_events_[tag]);
    736   msg.AppendAddress(code->address());
    737   msg.Append(",%d,\"", code->ExecutableSize());
    738   for (const char* p = comment; *p != '\0'; p++) {
    739     if (*p == '"') {
    740       msg.Append('\\');
    741     }
    742     msg.Append(*p);
    743   }
    744   msg.Append('"');
    745   if (FLAG_compress_log) {
    746     ASSERT(compression_helper_ != NULL);
    747     if (!compression_helper_->HandleMessage(&msg)) return;
    748   }
    749   msg.Append('\n');
    750   msg.WriteToLogFile();
    751 #endif
    752 }
    753 
    754 
    755 void Logger::CodeCreateEvent(LogEventsAndTags tag, Code* code, String* name) {
    756 #ifdef ENABLE_LOGGING_AND_PROFILING
    757   if (!Log::IsEnabled() || !FLAG_log_code) return;
    758   LogMessageBuilder msg;
    759   SmartPointer<char> str =
    760       name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    761   msg.Append("%s,%s,", log_events_[CODE_CREATION_EVENT], log_events_[tag]);
    762   msg.AppendAddress(code->address());
    763   msg.Append(",%d,\"%s\"", code->ExecutableSize(), *str);
    764   if (FLAG_compress_log) {
    765     ASSERT(compression_helper_ != NULL);
    766     if (!compression_helper_->HandleMessage(&msg)) return;
    767   }
    768   msg.Append('\n');
    769   msg.WriteToLogFile();
    770 #endif
    771 }
    772 
    773 
    774 void Logger::CodeCreateEvent(LogEventsAndTags tag,
    775                              Code* code, String* name,
    776                              String* source, int line) {
    777 #ifdef ENABLE_LOGGING_AND_PROFILING
    778   if (!Log::IsEnabled() || !FLAG_log_code) return;
    779   LogMessageBuilder msg;
    780   SmartPointer<char> str =
    781       name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    782   SmartPointer<char> sourcestr =
    783       source->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    784   msg.Append("%s,%s,", log_events_[CODE_CREATION_EVENT], log_events_[tag]);
    785   msg.AppendAddress(code->address());
    786   msg.Append(",%d,\"%s %s:%d\"",
    787              code->ExecutableSize(), *str, *sourcestr, line);
    788   if (FLAG_compress_log) {
    789     ASSERT(compression_helper_ != NULL);
    790     if (!compression_helper_->HandleMessage(&msg)) return;
    791   }
    792   msg.Append('\n');
    793   msg.WriteToLogFile();
    794 #endif
    795 }
    796 
    797 
    798 void Logger::CodeCreateEvent(LogEventsAndTags tag, Code* code, int args_count) {
    799 #ifdef ENABLE_LOGGING_AND_PROFILING
    800   if (!Log::IsEnabled() || !FLAG_log_code) return;
    801   LogMessageBuilder msg;
    802   msg.Append("%s,%s,", log_events_[CODE_CREATION_EVENT], log_events_[tag]);
    803   msg.AppendAddress(code->address());
    804   msg.Append(",%d,\"args_count: %d\"", code->ExecutableSize(), args_count);
    805   if (FLAG_compress_log) {
    806     ASSERT(compression_helper_ != NULL);
    807     if (!compression_helper_->HandleMessage(&msg)) return;
    808   }
    809   msg.Append('\n');
    810   msg.WriteToLogFile();
    811 #endif
    812 }
    813 
    814 
    815 void Logger::RegExpCodeCreateEvent(Code* code, String* source) {
    816 #ifdef ENABLE_LOGGING_AND_PROFILING
    817   if (!Log::IsEnabled() || !FLAG_log_code) return;
    818   LogMessageBuilder msg;
    819   msg.Append("%s,%s,",
    820              log_events_[CODE_CREATION_EVENT], log_events_[REG_EXP_TAG]);
    821   msg.AppendAddress(code->address());
    822   msg.Append(",%d,\"", code->ExecutableSize());
    823   msg.AppendDetailed(source, false);
    824   msg.Append('\"');
    825   if (FLAG_compress_log) {
    826     ASSERT(compression_helper_ != NULL);
    827     if (!compression_helper_->HandleMessage(&msg)) return;
    828   }
    829   msg.Append('\n');
    830   msg.WriteToLogFile();
    831 #endif
    832 }
    833 
    834 
    835 void Logger::CodeMoveEvent(Address from, Address to) {
    836 #ifdef ENABLE_LOGGING_AND_PROFILING
    837   MoveEventInternal(CODE_MOVE_EVENT, from, to);
    838 #endif
    839 }
    840 
    841 
    842 void Logger::CodeDeleteEvent(Address from) {
    843 #ifdef ENABLE_LOGGING_AND_PROFILING
    844   DeleteEventInternal(CODE_DELETE_EVENT, from);
    845 #endif
    846 }
    847 
    848 
    849 void Logger::SnapshotPositionEvent(Address addr, int pos) {
    850 #ifdef ENABLE_LOGGING_AND_PROFILING
    851   if (!Log::IsEnabled() || !FLAG_log_snapshot_positions) return;
    852   LogMessageBuilder msg;
    853   msg.Append("%s,", log_events_[SNAPSHOT_POSITION_EVENT]);
    854   msg.AppendAddress(addr);
    855   msg.Append(",%d", pos);
    856   if (FLAG_compress_log) {
    857     ASSERT(compression_helper_ != NULL);
    858     if (!compression_helper_->HandleMessage(&msg)) return;
    859   }
    860   msg.Append('\n');
    861   msg.WriteToLogFile();
    862 #endif
    863 }
    864 
    865 
    866 void Logger::FunctionCreateEvent(JSFunction* function) {
    867 #ifdef ENABLE_LOGGING_AND_PROFILING
    868   static Address prev_code = NULL;
    869   if (!Log::IsEnabled() || !FLAG_log_code) return;
    870   LogMessageBuilder msg;
    871   msg.Append("%s,", log_events_[FUNCTION_CREATION_EVENT]);
    872   msg.AppendAddress(function->address());
    873   msg.Append(',');
    874   msg.AppendAddress(function->code()->address(), prev_code);
    875   prev_code = function->code()->address();
    876   if (FLAG_compress_log) {
    877     ASSERT(compression_helper_ != NULL);
    878     if (!compression_helper_->HandleMessage(&msg)) return;
    879   }
    880   msg.Append('\n');
    881   msg.WriteToLogFile();
    882 #endif
    883 }
    884 
    885 
    886 void Logger::FunctionMoveEvent(Address from, Address to) {
    887 #ifdef ENABLE_LOGGING_AND_PROFILING
    888   MoveEventInternal(FUNCTION_MOVE_EVENT, from, to);
    889 #endif
    890 }
    891 
    892 
    893 void Logger::FunctionDeleteEvent(Address from) {
    894 #ifdef ENABLE_LOGGING_AND_PROFILING
    895   DeleteEventInternal(FUNCTION_DELETE_EVENT, from);
    896 #endif
    897 }
    898 
    899 
    900 #ifdef ENABLE_LOGGING_AND_PROFILING
    901 void Logger::MoveEventInternal(LogEventsAndTags event,
    902                                Address from,
    903                                Address to) {
    904   static Address prev_to_ = NULL;
    905   if (!Log::IsEnabled() || !FLAG_log_code) return;
    906   LogMessageBuilder msg;
    907   msg.Append("%s,", log_events_[event]);
    908   msg.AppendAddress(from);
    909   msg.Append(',');
    910   msg.AppendAddress(to, prev_to_);
    911   prev_to_ = to;
    912   if (FLAG_compress_log) {
    913     ASSERT(compression_helper_ != NULL);
    914     if (!compression_helper_->HandleMessage(&msg)) return;
    915   }
    916   msg.Append('\n');
    917   msg.WriteToLogFile();
    918 }
    919 #endif
    920 
    921 
    922 #ifdef ENABLE_LOGGING_AND_PROFILING
    923 void Logger::DeleteEventInternal(LogEventsAndTags event, Address from) {
    924   if (!Log::IsEnabled() || !FLAG_log_code) return;
    925   LogMessageBuilder msg;
    926   msg.Append("%s,", log_events_[event]);
    927   msg.AppendAddress(from);
    928   if (FLAG_compress_log) {
    929     ASSERT(compression_helper_ != NULL);
    930     if (!compression_helper_->HandleMessage(&msg)) return;
    931   }
    932   msg.Append('\n');
    933   msg.WriteToLogFile();
    934 }
    935 #endif
    936 
    937 
    938 void Logger::ResourceEvent(const char* name, const char* tag) {
    939 #ifdef ENABLE_LOGGING_AND_PROFILING
    940   if (!Log::IsEnabled() || !FLAG_log) return;
    941   LogMessageBuilder msg;
    942   msg.Append("%s,%s,", name, tag);
    943 
    944   uint32_t sec, usec;
    945   if (OS::GetUserTime(&sec, &usec) != -1) {
    946     msg.Append("%d,%d,", sec, usec);
    947   }
    948   msg.Append("%.0f", OS::TimeCurrentMillis());
    949 
    950   msg.Append('\n');
    951   msg.WriteToLogFile();
    952 #endif
    953 }
    954 
    955 
    956 void Logger::SuspectReadEvent(String* name, Object* obj) {
    957 #ifdef ENABLE_LOGGING_AND_PROFILING
    958   if (!Log::IsEnabled() || !FLAG_log_suspect) return;
    959   LogMessageBuilder msg;
    960   String* class_name = obj->IsJSObject()
    961                        ? JSObject::cast(obj)->class_name()
    962                        : Heap::empty_string();
    963   msg.Append("suspect-read,");
    964   msg.Append(class_name);
    965   msg.Append(',');
    966   msg.Append('"');
    967   msg.Append(name);
    968   msg.Append('"');
    969   msg.Append('\n');
    970   msg.WriteToLogFile();
    971 #endif
    972 }
    973 
    974 
    975 void Logger::HeapSampleBeginEvent(const char* space, const char* kind) {
    976 #ifdef ENABLE_LOGGING_AND_PROFILING
    977   if (!Log::IsEnabled() || !FLAG_log_gc) return;
    978   LogMessageBuilder msg;
    979   // Using non-relative system time in order to be able to synchronize with
    980   // external memory profiling events (e.g. DOM memory size).
    981   msg.Append("heap-sample-begin,\"%s\",\"%s\",%.0f\n",
    982              space, kind, OS::TimeCurrentMillis());
    983   msg.WriteToLogFile();
    984 #endif
    985 }
    986 
    987 
    988 void Logger::HeapSampleStats(const char* space, const char* kind,
    989                              int capacity, int used) {
    990 #ifdef ENABLE_LOGGING_AND_PROFILING
    991   if (!Log::IsEnabled() || !FLAG_log_gc) return;
    992   LogMessageBuilder msg;
    993   msg.Append("heap-sample-stats,\"%s\",\"%s\",%d,%d\n",
    994              space, kind, capacity, used);
    995   msg.WriteToLogFile();
    996 #endif
    997 }
    998 
    999 
   1000 void Logger::HeapSampleEndEvent(const char* space, const char* kind) {
   1001 #ifdef ENABLE_LOGGING_AND_PROFILING
   1002   if (!Log::IsEnabled() || !FLAG_log_gc) return;
   1003   LogMessageBuilder msg;
   1004   msg.Append("heap-sample-end,\"%s\",\"%s\"\n", space, kind);
   1005   msg.WriteToLogFile();
   1006 #endif
   1007 }
   1008 
   1009 
   1010 void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) {
   1011 #ifdef ENABLE_LOGGING_AND_PROFILING
   1012   if (!Log::IsEnabled() || !FLAG_log_gc) return;
   1013   LogMessageBuilder msg;
   1014   msg.Append("heap-sample-item,%s,%d,%d\n", type, number, bytes);
   1015   msg.WriteToLogFile();
   1016 #endif
   1017 }
   1018 
   1019 
   1020 void Logger::HeapSampleJSConstructorEvent(const char* constructor,
   1021                                           int number, int bytes) {
   1022 #ifdef ENABLE_LOGGING_AND_PROFILING
   1023   if (!Log::IsEnabled() || !FLAG_log_gc) return;
   1024   LogMessageBuilder msg;
   1025   msg.Append("heap-js-cons-item,%s,%d,%d\n", constructor, number, bytes);
   1026   msg.WriteToLogFile();
   1027 #endif
   1028 }
   1029 
   1030 
   1031 void Logger::HeapSampleJSRetainersEvent(
   1032     const char* constructor, const char* event) {
   1033 #ifdef ENABLE_LOGGING_AND_PROFILING
   1034   if (!Log::IsEnabled() || !FLAG_log_gc) return;
   1035   // Event starts with comma, so we don't have it in the format string.
   1036   static const char* event_text = "heap-js-ret-item,%s";
   1037   // We take placeholder strings into account, but it's OK to be conservative.
   1038   static const int event_text_len = StrLength(event_text);
   1039   const int cons_len = StrLength(constructor);
   1040   const int event_len = StrLength(event);
   1041   int pos = 0;
   1042   // Retainer lists can be long. We may need to split them into multiple events.
   1043   do {
   1044     LogMessageBuilder msg;
   1045     msg.Append(event_text, constructor);
   1046     int to_write = event_len - pos;
   1047     if (to_write > Log::kMessageBufferSize - (cons_len + event_text_len)) {
   1048       int cut_pos = pos + Log::kMessageBufferSize - (cons_len + event_text_len);
   1049       ASSERT(cut_pos < event_len);
   1050       while (cut_pos > pos && event[cut_pos] != ',') --cut_pos;
   1051       if (event[cut_pos] != ',') {
   1052         // Crash in debug mode, skip in release mode.
   1053         ASSERT(false);
   1054         return;
   1055       }
   1056       // Append a piece of event that fits, without trailing comma.
   1057       msg.AppendStringPart(event + pos, cut_pos - pos);
   1058       // Start next piece with comma.
   1059       pos = cut_pos;
   1060     } else {
   1061       msg.Append("%s", event + pos);
   1062       pos += event_len;
   1063     }
   1064     msg.Append('\n');
   1065     msg.WriteToLogFile();
   1066   } while (pos < event_len);
   1067 #endif
   1068 }
   1069 
   1070 
   1071 void Logger::HeapSampleJSProducerEvent(const char* constructor,
   1072                                        Address* stack) {
   1073 #ifdef ENABLE_LOGGING_AND_PROFILING
   1074   if (!Log::IsEnabled() || !FLAG_log_gc) return;
   1075   LogMessageBuilder msg;
   1076   msg.Append("heap-js-prod-item,%s", constructor);
   1077   while (*stack != NULL) {
   1078     msg.Append(",0x%" V8PRIxPTR, *stack++);
   1079   }
   1080   msg.Append("\n");
   1081   msg.WriteToLogFile();
   1082 #endif
   1083 }
   1084 
   1085 
   1086 void Logger::DebugTag(const char* call_site_tag) {
   1087 #ifdef ENABLE_LOGGING_AND_PROFILING
   1088   if (!Log::IsEnabled() || !FLAG_log) return;
   1089   LogMessageBuilder msg;
   1090   msg.Append("debug-tag,%s\n", call_site_tag);
   1091   msg.WriteToLogFile();
   1092 #endif
   1093 }
   1094 
   1095 
   1096 void Logger::DebugEvent(const char* event_type, Vector<uint16_t> parameter) {
   1097 #ifdef ENABLE_LOGGING_AND_PROFILING
   1098   if (!Log::IsEnabled() || !FLAG_log) return;
   1099   StringBuilder s(parameter.length() + 1);
   1100   for (int i = 0; i < parameter.length(); ++i) {
   1101     s.AddCharacter(static_cast<char>(parameter[i]));
   1102   }
   1103   char* parameter_string = s.Finalize();
   1104   LogMessageBuilder msg;
   1105   msg.Append("debug-queue-event,%s,%15.3f,%s\n",
   1106              event_type,
   1107              OS::TimeCurrentMillis(),
   1108              parameter_string);
   1109   DeleteArray(parameter_string);
   1110   msg.WriteToLogFile();
   1111 #endif
   1112 }
   1113 
   1114 
   1115 #ifdef ENABLE_LOGGING_AND_PROFILING
   1116 void Logger::TickEvent(TickSample* sample, bool overflow) {
   1117   if (!Log::IsEnabled() || !FLAG_prof) return;
   1118   static Address prev_sp = NULL;
   1119   static Address prev_function = NULL;
   1120   LogMessageBuilder msg;
   1121   msg.Append("%s,", log_events_[TICK_EVENT]);
   1122   Address prev_addr = sample->pc;
   1123   msg.AppendAddress(prev_addr);
   1124   msg.Append(',');
   1125   msg.AppendAddress(sample->sp, prev_sp);
   1126   prev_sp = sample->sp;
   1127   msg.Append(',');
   1128   msg.AppendAddress(sample->function, prev_function);
   1129   prev_function = sample->function;
   1130   msg.Append(",%d", static_cast<int>(sample->state));
   1131   if (overflow) {
   1132     msg.Append(",overflow");
   1133   }
   1134   for (int i = 0; i < sample->frames_count; ++i) {
   1135     msg.Append(',');
   1136     msg.AppendAddress(sample->stack[i], prev_addr);
   1137     prev_addr = sample->stack[i];
   1138   }
   1139   if (FLAG_compress_log) {
   1140     ASSERT(compression_helper_ != NULL);
   1141     if (!compression_helper_->HandleMessage(&msg)) return;
   1142   }
   1143   msg.Append('\n');
   1144   msg.WriteToLogFile();
   1145 }
   1146 
   1147 
   1148 int Logger::GetActiveProfilerModules() {
   1149   int result = PROFILER_MODULE_NONE;
   1150   if (!profiler_->paused()) {
   1151     result |= PROFILER_MODULE_CPU;
   1152   }
   1153   if (FLAG_log_gc) {
   1154     result |= PROFILER_MODULE_HEAP_STATS | PROFILER_MODULE_JS_CONSTRUCTORS;
   1155   }
   1156   return result;
   1157 }
   1158 
   1159 
   1160 void Logger::PauseProfiler(int flags, int tag) {
   1161   if (!Log::IsEnabled()) return;
   1162   if (flags & PROFILER_MODULE_CPU) {
   1163     // It is OK to have negative nesting.
   1164     if (--cpu_profiler_nesting_ == 0) {
   1165       profiler_->pause();
   1166       if (FLAG_prof_lazy) {
   1167         if (!FLAG_sliding_state_window) ticker_->Stop();
   1168         FLAG_log_code = false;
   1169         // Must be the same message as Log::kDynamicBufferSeal.
   1170         LOG(UncheckedStringEvent("profiler", "pause"));
   1171       }
   1172     }
   1173   }
   1174   if (flags &
   1175       (PROFILER_MODULE_HEAP_STATS | PROFILER_MODULE_JS_CONSTRUCTORS)) {
   1176     if (--heap_profiler_nesting_ == 0) {
   1177       FLAG_log_gc = false;
   1178     }
   1179   }
   1180   if (tag != 0) {
   1181     IntEvent("close-tag", tag);
   1182   }
   1183   if (GetActiveProfilerModules() == PROFILER_MODULE_NONE) {
   1184     is_logging_ = false;
   1185   }
   1186 }
   1187 
   1188 
   1189 void Logger::ResumeProfiler(int flags, int tag) {
   1190   if (!Log::IsEnabled()) return;
   1191   if (tag != 0) {
   1192     IntEvent("open-tag", tag);
   1193   }
   1194   if (flags & PROFILER_MODULE_CPU) {
   1195     if (cpu_profiler_nesting_++ == 0) {
   1196       is_logging_ = true;
   1197       if (FLAG_prof_lazy) {
   1198         profiler_->Engage();
   1199         LOG(UncheckedStringEvent("profiler", "resume"));
   1200         FLAG_log_code = true;
   1201         LogCompiledFunctions();
   1202         LogFunctionObjects();
   1203         LogAccessorCallbacks();
   1204         if (!FLAG_sliding_state_window) ticker_->Start();
   1205       }
   1206       profiler_->resume();
   1207     }
   1208   }
   1209   if (flags &
   1210       (PROFILER_MODULE_HEAP_STATS | PROFILER_MODULE_JS_CONSTRUCTORS)) {
   1211     if (heap_profiler_nesting_++ == 0) {
   1212       is_logging_ = true;
   1213       FLAG_log_gc = true;
   1214     }
   1215   }
   1216 }
   1217 
   1218 
   1219 // This function can be called when Log's mutex is acquired,
   1220 // either from main or Profiler's thread.
   1221 void Logger::StopLoggingAndProfiling() {
   1222   Log::stop();
   1223   PauseProfiler(PROFILER_MODULE_CPU, 0);
   1224 }
   1225 
   1226 
   1227 bool Logger::IsProfilerSamplerActive() {
   1228   return ticker_->IsActive();
   1229 }
   1230 
   1231 
   1232 int Logger::GetLogLines(int from_pos, char* dest_buf, int max_size) {
   1233   return Log::GetLogLines(from_pos, dest_buf, max_size);
   1234 }
   1235 
   1236 
   1237 static int EnumerateCompiledFunctions(Handle<SharedFunctionInfo>* sfis) {
   1238   AssertNoAllocation no_alloc;
   1239   int compiled_funcs_count = 0;
   1240   HeapIterator iterator;
   1241   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
   1242     if (!obj->IsSharedFunctionInfo()) continue;
   1243     SharedFunctionInfo* sfi = SharedFunctionInfo::cast(obj);
   1244     if (sfi->is_compiled()
   1245         && (!sfi->script()->IsScript()
   1246             || Script::cast(sfi->script())->HasValidSource())) {
   1247       if (sfis != NULL)
   1248         sfis[compiled_funcs_count] = Handle<SharedFunctionInfo>(sfi);
   1249       ++compiled_funcs_count;
   1250     }
   1251   }
   1252   return compiled_funcs_count;
   1253 }
   1254 
   1255 
   1256 void Logger::LogCodeObject(Object* object) {
   1257   if (FLAG_log_code) {
   1258     Code* code_object = Code::cast(object);
   1259     LogEventsAndTags tag = Logger::STUB_TAG;
   1260     const char* description = "Unknown code from the snapshot";
   1261     switch (code_object->kind()) {
   1262       case Code::FUNCTION:
   1263         return;  // We log this later using LogCompiledFunctions.
   1264       case Code::STUB:
   1265         description = CodeStub::MajorName(code_object->major_key(), true);
   1266         if (description == NULL)
   1267           description = "A stub from the snapshot";
   1268         tag = Logger::STUB_TAG;
   1269         break;
   1270       case Code::BUILTIN:
   1271         description = "A builtin from the snapshot";
   1272         tag = Logger::BUILTIN_TAG;
   1273         break;
   1274       case Code::KEYED_LOAD_IC:
   1275         description = "A keyed load IC from the snapshot";
   1276         tag = Logger::KEYED_LOAD_IC_TAG;
   1277         break;
   1278       case Code::LOAD_IC:
   1279         description = "A load IC from the snapshot";
   1280         tag = Logger::LOAD_IC_TAG;
   1281         break;
   1282       case Code::STORE_IC:
   1283         description = "A store IC from the snapshot";
   1284         tag = Logger::STORE_IC_TAG;
   1285         break;
   1286       case Code::KEYED_STORE_IC:
   1287         description = "A keyed store IC from the snapshot";
   1288         tag = Logger::KEYED_STORE_IC_TAG;
   1289         break;
   1290       case Code::CALL_IC:
   1291         description = "A call IC from the snapshot";
   1292         tag = Logger::CALL_IC_TAG;
   1293         break;
   1294     }
   1295     LOG(CodeCreateEvent(tag, code_object, description));
   1296   }
   1297 }
   1298 
   1299 
   1300 void Logger::LogCodeObjects() {
   1301   AssertNoAllocation no_alloc;
   1302   HeapIterator iterator;
   1303   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
   1304     if (obj->IsCode()) LogCodeObject(obj);
   1305   }
   1306 }
   1307 
   1308 
   1309 void Logger::LogCompiledFunctions() {
   1310   HandleScope scope;
   1311   const int compiled_funcs_count = EnumerateCompiledFunctions(NULL);
   1312   Handle<SharedFunctionInfo>* sfis =
   1313       NewArray< Handle<SharedFunctionInfo> >(compiled_funcs_count);
   1314   EnumerateCompiledFunctions(sfis);
   1315 
   1316   // During iteration, there can be heap allocation due to
   1317   // GetScriptLineNumber call.
   1318   for (int i = 0; i < compiled_funcs_count; ++i) {
   1319     Handle<SharedFunctionInfo> shared = sfis[i];
   1320     Handle<String> name(String::cast(shared->name()));
   1321     Handle<String> func_name(name->length() > 0 ?
   1322                              *name : shared->inferred_name());
   1323     if (shared->script()->IsScript()) {
   1324       Handle<Script> script(Script::cast(shared->script()));
   1325       if (script->name()->IsString()) {
   1326         Handle<String> script_name(String::cast(script->name()));
   1327         int line_num = GetScriptLineNumber(script, shared->start_position());
   1328         if (line_num > 0) {
   1329           LOG(CodeCreateEvent(Logger::LAZY_COMPILE_TAG,
   1330                               shared->code(), *func_name,
   1331                               *script_name, line_num + 1));
   1332         } else {
   1333           // Can't distinguish enum and script here, so always use Script.
   1334           LOG(CodeCreateEvent(Logger::SCRIPT_TAG,
   1335                               shared->code(), *script_name));
   1336         }
   1337       } else {
   1338         LOG(CodeCreateEvent(
   1339             Logger::LAZY_COMPILE_TAG, shared->code(), *func_name));
   1340       }
   1341     } else if (shared->function_data()->IsFunctionTemplateInfo()) {
   1342       // API function.
   1343       FunctionTemplateInfo* fun_data =
   1344           FunctionTemplateInfo::cast(shared->function_data());
   1345       Object* raw_call_data = fun_data->call_code();
   1346       if (!raw_call_data->IsUndefined()) {
   1347         CallHandlerInfo* call_data = CallHandlerInfo::cast(raw_call_data);
   1348         Object* callback_obj = call_data->callback();
   1349         Address entry_point = v8::ToCData<Address>(callback_obj);
   1350         LOG(CallbackEvent(*func_name, entry_point));
   1351       }
   1352     } else {
   1353       LOG(CodeCreateEvent(
   1354           Logger::LAZY_COMPILE_TAG, shared->code(), *func_name));
   1355     }
   1356   }
   1357 
   1358   DeleteArray(sfis);
   1359 }
   1360 
   1361 
   1362 void Logger::LogFunctionObjects() {
   1363   AssertNoAllocation no_alloc;
   1364   HeapIterator iterator;
   1365   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
   1366     if (!obj->IsJSFunction()) continue;
   1367     JSFunction* jsf = JSFunction::cast(obj);
   1368     if (!jsf->is_compiled()) continue;
   1369     LOG(FunctionCreateEvent(jsf));
   1370   }
   1371 }
   1372 
   1373 
   1374 void Logger::LogAccessorCallbacks() {
   1375   AssertNoAllocation no_alloc;
   1376   HeapIterator iterator;
   1377   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
   1378     if (!obj->IsAccessorInfo()) continue;
   1379     AccessorInfo* ai = AccessorInfo::cast(obj);
   1380     if (!ai->name()->IsString()) continue;
   1381     String* name = String::cast(ai->name());
   1382     Address getter_entry = v8::ToCData<Address>(ai->getter());
   1383     if (getter_entry != 0) {
   1384       LOG(GetterCallbackEvent(name, getter_entry));
   1385     }
   1386     Address setter_entry = v8::ToCData<Address>(ai->setter());
   1387     if (setter_entry != 0) {
   1388       LOG(SetterCallbackEvent(name, setter_entry));
   1389     }
   1390   }
   1391 }
   1392 
   1393 #endif
   1394 
   1395 
   1396 bool Logger::Setup() {
   1397 #ifdef ENABLE_LOGGING_AND_PROFILING
   1398   // --log-all enables all the log flags.
   1399   if (FLAG_log_all) {
   1400     FLAG_log_runtime = true;
   1401     FLAG_log_api = true;
   1402     FLAG_log_code = true;
   1403     FLAG_log_gc = true;
   1404     FLAG_log_suspect = true;
   1405     FLAG_log_handles = true;
   1406     FLAG_log_regexp = true;
   1407   }
   1408 
   1409   // --prof implies --log-code.
   1410   if (FLAG_prof) FLAG_log_code = true;
   1411 
   1412   // --prof_lazy controls --log-code, implies --noprof_auto.
   1413   if (FLAG_prof_lazy) {
   1414     FLAG_log_code = false;
   1415     FLAG_prof_auto = false;
   1416   }
   1417 
   1418   bool start_logging = FLAG_log || FLAG_log_runtime || FLAG_log_api
   1419       || FLAG_log_code || FLAG_log_gc || FLAG_log_handles || FLAG_log_suspect
   1420       || FLAG_log_regexp || FLAG_log_state_changes;
   1421 
   1422   bool open_log_file = start_logging || FLAG_prof_lazy;
   1423 
   1424   // If we're logging anything, we need to open the log file.
   1425   if (open_log_file) {
   1426     if (strcmp(FLAG_logfile, "-") == 0) {
   1427       Log::OpenStdout();
   1428     } else if (strcmp(FLAG_logfile, "*") == 0) {
   1429       Log::OpenMemoryBuffer();
   1430     } else if (strchr(FLAG_logfile, '%') != NULL) {
   1431       // If there's a '%' in the log file name we have to expand
   1432       // placeholders.
   1433       HeapStringAllocator allocator;
   1434       StringStream stream(&allocator);
   1435       for (const char* p = FLAG_logfile; *p; p++) {
   1436         if (*p == '%') {
   1437           p++;
   1438           switch (*p) {
   1439             case '\0':
   1440               // If there's a % at the end of the string we back up
   1441               // one character so we can escape the loop properly.
   1442               p--;
   1443               break;
   1444             case 't': {
   1445               // %t expands to the current time in milliseconds.
   1446               double time = OS::TimeCurrentMillis();
   1447               stream.Add("%.0f", FmtElm(time));
   1448               break;
   1449             }
   1450             case '%':
   1451               // %% expands (contracts really) to %.
   1452               stream.Put('%');
   1453               break;
   1454             default:
   1455               // All other %'s expand to themselves.
   1456               stream.Put('%');
   1457               stream.Put(*p);
   1458               break;
   1459           }
   1460         } else {
   1461           stream.Put(*p);
   1462         }
   1463       }
   1464       SmartPointer<const char> expanded = stream.ToCString();
   1465       Log::OpenFile(*expanded);
   1466     } else {
   1467       Log::OpenFile(FLAG_logfile);
   1468     }
   1469   }
   1470 
   1471   current_state_ = &bottom_state_;
   1472 
   1473   ticker_ = new Ticker(kSamplingIntervalMs);
   1474 
   1475   if (FLAG_sliding_state_window && sliding_state_window_ == NULL) {
   1476     sliding_state_window_ = new SlidingStateWindow();
   1477   }
   1478 
   1479   log_events_ = FLAG_compress_log ?
   1480       kCompressedLogEventsNames : kLongLogEventsNames;
   1481   if (FLAG_compress_log) {
   1482     compression_helper_ = new CompressionHelper(kCompressionWindowSize);
   1483   }
   1484 
   1485   is_logging_ = start_logging;
   1486 
   1487   if (FLAG_prof) {
   1488     profiler_ = new Profiler();
   1489     if (!FLAG_prof_auto) {
   1490       profiler_->pause();
   1491     } else {
   1492       is_logging_ = true;
   1493     }
   1494     if (!FLAG_prof_lazy) {
   1495       profiler_->Engage();
   1496     }
   1497   }
   1498 
   1499   LogMessageBuilder::set_write_failure_handler(StopLoggingAndProfiling);
   1500 
   1501   return true;
   1502 
   1503 #else
   1504   return false;
   1505 #endif
   1506 }
   1507 
   1508 
   1509 void Logger::TearDown() {
   1510 #ifdef ENABLE_LOGGING_AND_PROFILING
   1511   LogMessageBuilder::set_write_failure_handler(NULL);
   1512 
   1513   // Stop the profiler before closing the file.
   1514   if (profiler_ != NULL) {
   1515     profiler_->Disengage();
   1516     delete profiler_;
   1517     profiler_ = NULL;
   1518   }
   1519 
   1520   delete compression_helper_;
   1521   compression_helper_ = NULL;
   1522 
   1523   delete sliding_state_window_;
   1524   sliding_state_window_ = NULL;
   1525 
   1526   delete ticker_;
   1527   ticker_ = NULL;
   1528 
   1529   Log::Close();
   1530 #endif
   1531 }
   1532 
   1533 
   1534 void Logger::EnableSlidingStateWindow() {
   1535 #ifdef ENABLE_LOGGING_AND_PROFILING
   1536   // If the ticker is NULL, Logger::Setup has not been called yet.  In
   1537   // that case, we set the sliding_state_window flag so that the
   1538   // sliding window computation will be started when Logger::Setup is
   1539   // called.
   1540   if (ticker_ == NULL) {
   1541     FLAG_sliding_state_window = true;
   1542     return;
   1543   }
   1544   // Otherwise, if the sliding state window computation has not been
   1545   // started we do it now.
   1546   if (sliding_state_window_ == NULL) {
   1547     sliding_state_window_ = new SlidingStateWindow();
   1548   }
   1549 #endif
   1550 }
   1551 
   1552 
   1553 } }  // namespace v8::internal
   1554