LCOV - code coverage report
Current view: top level - src - log.cc (source / functions) Hit Total Coverage
Test: app.info Lines: 381 878 43.4 %
Date: 2017-04-26 Functions: 64 138 46.4 %

          Line data    Source code
       1             : // Copyright 2011 the V8 project authors. All rights reserved.
       2             : // Use of this source code is governed by a BSD-style license that can be
       3             : // found in the LICENSE file.
       4             : 
       5             : #include "src/log.h"
       6             : 
       7             : #include <cstdarg>
       8             : #include <memory>
       9             : #include <sstream>
      10             : 
      11             : #include "src/bailout-reason.h"
      12             : #include "src/base/platform/platform.h"
      13             : #include "src/bootstrapper.h"
      14             : #include "src/code-stubs.h"
      15             : #include "src/counters.h"
      16             : #include "src/deoptimizer.h"
      17             : #include "src/global-handles.h"
      18             : #include "src/interpreter/bytecodes.h"
      19             : #include "src/interpreter/interpreter.h"
      20             : #include "src/libsampler/sampler.h"
      21             : #include "src/log-inl.h"
      22             : #include "src/log-utils.h"
      23             : #include "src/macro-assembler.h"
      24             : #include "src/perf-jit.h"
      25             : #include "src/profiler/profiler-listener.h"
      26             : #include "src/profiler/tick-sample.h"
      27             : #include "src/runtime-profiler.h"
      28             : #include "src/source-position-table.h"
      29             : #include "src/string-stream.h"
      30             : #include "src/tracing/tracing-category-observer.h"
      31             : #include "src/vm-state-inl.h"
      32             : 
      33             : namespace v8 {
      34             : namespace internal {
      35             : 
      36             : #define DECLARE_EVENT(ignore1, name) name,
      37             : static const char* kLogEventsNames[CodeEventListener::NUMBER_OF_LOG_EVENTS] = {
      38             :     LOG_EVENTS_AND_TAGS_LIST(DECLARE_EVENT)};
      39             : #undef DECLARE_EVENT
      40             : 
      41       21721 : static const char* ComputeMarker(SharedFunctionInfo* shared,
      42             :                                  AbstractCode* code) {
      43       21721 :   switch (code->kind()) {
      44             :     case AbstractCode::FUNCTION:
      45             :     case AbstractCode::INTERPRETED_FUNCTION:
      46         592 :       return shared->optimization_disabled() ? "" : "~";
      47             :     case AbstractCode::OPTIMIZED_FUNCTION:
      48             :       return "*";
      49             :     default:
      50       21048 :       return "";
      51             :   }
      52             : }
      53             : 
      54             : 
      55             : class CodeEventLogger::NameBuffer {
      56             :  public:
      57             :   NameBuffer() { Reset(); }
      58             : 
      59             :   void Reset() {
      60       11916 :     utf8_pos_ = 0;
      61             :   }
      62             : 
      63       11581 :   void Init(CodeEventListener::LogEventsAndTags tag) {
      64             :     Reset();
      65       11581 :     AppendBytes(kLogEventsNames[tag]);
      66             :     AppendByte(':');
      67       11581 :   }
      68             : 
      69        5373 :   void AppendName(Name* name) {
      70        5373 :     if (name->IsString()) {
      71        5373 :       AppendString(String::cast(name));
      72             :     } else {
      73             :       Symbol* symbol = Symbol::cast(name);
      74           0 :       AppendBytes("symbol(");
      75           0 :       if (!symbol->name()->IsUndefined(symbol->GetIsolate())) {
      76           0 :         AppendBytes("\"");
      77           0 :         AppendString(String::cast(symbol->name()));
      78           0 :         AppendBytes("\" ");
      79             :       }
      80           0 :       AppendBytes("hash ");
      81           0 :       AppendHex(symbol->Hash());
      82             :       AppendByte(')');
      83             :     }
      84        5373 :   }
      85             : 
      86        6441 :   void AppendString(String* str) {
      87       12882 :     if (str == NULL) return;
      88             :     int uc16_length = Min(str->length(), kUtf16BufferSize);
      89        6441 :     String::WriteToFlat(str, utf16_buffer, 0, uc16_length);
      90             :     int previous = unibrow::Utf16::kNoPreviousCharacter;
      91       14165 :     for (int i = 0; i < uc16_length && utf8_pos_ < kUtf8BufferSize; ++i) {
      92        7724 :       uc16 c = utf16_buffer[i];
      93        7724 :       if (c <= unibrow::Utf8::kMaxOneByteChar) {
      94        7724 :         utf8_buffer_[utf8_pos_++] = static_cast<char>(c);
      95             :       } else {
      96           0 :         int char_length = unibrow::Utf8::Length(c, previous);
      97           0 :         if (utf8_pos_ + char_length > kUtf8BufferSize) break;
      98           0 :         unibrow::Utf8::Encode(utf8_buffer_ + utf8_pos_, c, previous);
      99           0 :         utf8_pos_ += char_length;
     100             :       }
     101        7724 :       previous = c;
     102             :     }
     103             :   }
     104             : 
     105       23162 :   void AppendBytes(const char* bytes, int size) {
     106       23162 :     size = Min(size, kUtf8BufferSize - utf8_pos_);
     107       23162 :     MemCopy(utf8_buffer_ + utf8_pos_, bytes, size);
     108       23162 :     utf8_pos_ += size;
     109       23162 :   }
     110             : 
     111       23162 :   void AppendBytes(const char* bytes) {
     112       23162 :     AppendBytes(bytes, StrLength(bytes));
     113       23162 :   }
     114             : 
     115             :   void AppendByte(char c) {
     116       12649 :     if (utf8_pos_ >= kUtf8BufferSize) return;
     117       12625 :     utf8_buffer_[utf8_pos_++] = c;
     118             :   }
     119             : 
     120         534 :   void AppendInt(int n) {
     121         534 :     int space = kUtf8BufferSize - utf8_pos_;
     122         546 :     if (space <= 0) return;
     123         522 :     Vector<char> buffer(utf8_buffer_ + utf8_pos_, space);
     124         522 :     int size = SNPrintF(buffer, "%d", n);
     125         522 :     if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {
     126         522 :       utf8_pos_ += size;
     127             :     }
     128             :   }
     129             : 
     130           0 :   void AppendHex(uint32_t n) {
     131           0 :     int space = kUtf8BufferSize - utf8_pos_;
     132           0 :     if (space <= 0) return;
     133           0 :     Vector<char> buffer(utf8_buffer_ + utf8_pos_, space);
     134           0 :     int size = SNPrintF(buffer, "%x", n);
     135           0 :     if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {
     136           0 :       utf8_pos_ += size;
     137             :     }
     138             :   }
     139             : 
     140             :   const char* get() { return utf8_buffer_; }
     141             :   int size() const { return utf8_pos_; }
     142             : 
     143             :  private:
     144             :   static const int kUtf8BufferSize = 512;
     145             :   static const int kUtf16BufferSize = kUtf8BufferSize;
     146             : 
     147             :   int utf8_pos_;
     148             :   char utf8_buffer_[kUtf8BufferSize];
     149             :   uc16 utf16_buffer[kUtf16BufferSize];
     150             : };
     151             : 
     152             : 
     153         966 : CodeEventLogger::CodeEventLogger() : name_buffer_(new NameBuffer) { }
     154             : 
     155         631 : CodeEventLogger::~CodeEventLogger() { delete name_buffer_; }
     156             : 
     157        5674 : void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
     158             :                                       AbstractCode* code, const char* comment) {
     159       11348 :   name_buffer_->Init(tag);
     160        5674 :   name_buffer_->AppendBytes(comment);
     161       11348 :   LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());
     162        5674 : }
     163             : 
     164           0 : void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
     165             :                                       AbstractCode* code, Name* name) {
     166           0 :   name_buffer_->Init(tag);
     167           0 :   name_buffer_->AppendName(name);
     168           0 :   LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());
     169           0 : }
     170             : 
     171        5373 : void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
     172             :                                       AbstractCode* code,
     173             :                                       SharedFunctionInfo* shared, Name* name) {
     174       10746 :   name_buffer_->Init(tag);
     175        5373 :   name_buffer_->AppendBytes(ComputeMarker(shared, code));
     176        5373 :   name_buffer_->AppendName(name);
     177       10746 :   LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());
     178        5373 : }
     179             : 
     180         534 : void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
     181             :                                       AbstractCode* code,
     182             :                                       SharedFunctionInfo* shared, Name* source,
     183             :                                       int line, int column) {
     184        1068 :   name_buffer_->Init(tag);
     185         534 :   name_buffer_->AppendBytes(ComputeMarker(shared, code));
     186         534 :   name_buffer_->AppendString(shared->DebugName());
     187         534 :   name_buffer_->AppendByte(' ');
     188         534 :   if (source->IsString()) {
     189         534 :     name_buffer_->AppendString(String::cast(source));
     190             :   } else {
     191           0 :     name_buffer_->AppendBytes("symbol(hash ");
     192           0 :     name_buffer_->AppendHex(Name::cast(source)->Hash());
     193           0 :     name_buffer_->AppendByte(')');
     194             :   }
     195         534 :   name_buffer_->AppendByte(':');
     196         534 :   name_buffer_->AppendInt(line);
     197        1068 :   LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());
     198         534 : }
     199             : 
     200           0 : void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
     201             :                                       AbstractCode* code, int args_count) {
     202           0 :   name_buffer_->Init(tag);
     203           0 :   name_buffer_->AppendInt(args_count);
     204           0 :   LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());
     205           0 : }
     206             : 
     207           0 : void CodeEventLogger::RegExpCodeCreateEvent(AbstractCode* code,
     208             :                                             String* source) {
     209           0 :   name_buffer_->Init(CodeEventListener::REG_EXP_TAG);
     210           0 :   name_buffer_->AppendString(source);
     211           0 :   LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());
     212           0 : }
     213             : 
     214             : 
     215             : // Linux perf tool logging support
     216             : class PerfBasicLogger : public CodeEventLogger {
     217             :  public:
     218             :   PerfBasicLogger();
     219             :   ~PerfBasicLogger() override;
     220             : 
     221           0 :   void CodeMoveEvent(AbstractCode* from, Address to) override {}
     222           0 :   void CodeDisableOptEvent(AbstractCode* code,
     223           0 :                            SharedFunctionInfo* shared) override {}
     224             : 
     225             :  private:
     226             :   void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
     227             :                          const char* name, int length) override;
     228             : 
     229             :   // Extension added to V8 log file name to get the low-level log name.
     230             :   static const char kFilenameFormatString[];
     231             :   static const int kFilenameBufferPadding;
     232             : 
     233             :   FILE* perf_output_handle_;
     234             : };
     235             : 
     236             : const char PerfBasicLogger::kFilenameFormatString[] = "/tmp/perf-%d.map";
     237             : // Extra space for the PID in the filename
     238             : const int PerfBasicLogger::kFilenameBufferPadding = 16;
     239             : 
     240           0 : PerfBasicLogger::PerfBasicLogger()
     241           0 :     : perf_output_handle_(NULL) {
     242             :   // Open the perf JIT dump file.
     243             :   int bufferSize = sizeof(kFilenameFormatString) + kFilenameBufferPadding;
     244             :   ScopedVector<char> perf_dump_name(bufferSize);
     245             :   int size = SNPrintF(
     246             :       perf_dump_name,
     247             :       kFilenameFormatString,
     248           0 :       base::OS::GetCurrentProcessId());
     249           0 :   CHECK_NE(size, -1);
     250             :   perf_output_handle_ =
     251           0 :       base::OS::FOpen(perf_dump_name.start(), base::OS::LogFileOpenMode);
     252           0 :   CHECK_NOT_NULL(perf_output_handle_);
     253           0 :   setvbuf(perf_output_handle_, NULL, _IOLBF, 0);
     254           0 : }
     255             : 
     256             : 
     257           0 : PerfBasicLogger::~PerfBasicLogger() {
     258           0 :   fclose(perf_output_handle_);
     259           0 :   perf_output_handle_ = NULL;
     260           0 : }
     261             : 
     262           0 : void PerfBasicLogger::LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo*,
     263             :                                         const char* name, int length) {
     264           0 :   if (FLAG_perf_basic_prof_only_functions &&
     265           0 :       (code->kind() != AbstractCode::FUNCTION &&
     266           0 :        code->kind() != AbstractCode::INTERPRETED_FUNCTION &&
     267           0 :        code->kind() != AbstractCode::OPTIMIZED_FUNCTION)) {
     268           0 :     return;
     269             :   }
     270             : 
     271             :   // Linux perf expects hex literals without a leading 0x, while some
     272             :   // implementations of printf might prepend one when using the %p format
     273             :   // for pointers, leading to wrongly formatted JIT symbols maps.
     274             :   //
     275             :   // Instead, we use V8PRIxPTR format string and cast pointer to uintpr_t,
     276             :   // so that we have control over the exact output format.
     277             :   base::OS::FPrint(perf_output_handle_, "%" V8PRIxPTR " %x %.*s\n",
     278           0 :                    reinterpret_cast<uintptr_t>(code->instruction_start()),
     279           0 :                    code->instruction_size(), length, name);
     280             : }
     281             : 
     282             : // Low-level logging support.
     283             : #define LL_LOG(Call) if (ll_logger_) ll_logger_->Call;
     284             : 
     285             : class LowLevelLogger : public CodeEventLogger {
     286             :  public:
     287             :   explicit LowLevelLogger(const char* file_name);
     288             :   ~LowLevelLogger() override;
     289             : 
     290             :   void CodeMoveEvent(AbstractCode* from, Address to) override;
     291           0 :   void CodeDisableOptEvent(AbstractCode* code,
     292           0 :                            SharedFunctionInfo* shared) override {}
     293             :   void SnapshotPositionEvent(HeapObject* obj, int pos);
     294             :   void CodeMovingGCEvent() override;
     295             : 
     296             :  private:
     297             :   void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
     298             :                          const char* name, int length) override;
     299             : 
     300             :   // Low-level profiling event structures.
     301             :   struct CodeCreateStruct {
     302             :     static const char kTag = 'C';
     303             : 
     304             :     int32_t name_size;
     305             :     Address code_address;
     306             :     int32_t code_size;
     307             :   };
     308             : 
     309             : 
     310             :   struct CodeMoveStruct {
     311             :     static const char kTag = 'M';
     312             : 
     313             :     Address from_address;
     314             :     Address to_address;
     315             :   };
     316             : 
     317             : 
     318             :   static const char kCodeMovingGCTag = 'G';
     319             : 
     320             : 
     321             :   // Extension added to V8 log file name to get the low-level log name.
     322             :   static const char kLogExt[];
     323             : 
     324             :   void LogCodeInfo();
     325             :   void LogWriteBytes(const char* bytes, int size);
     326             : 
     327             :   template <typename T>
     328           0 :   void LogWriteStruct(const T& s) {
     329           0 :     char tag = T::kTag;
     330             :     LogWriteBytes(reinterpret_cast<const char*>(&tag), sizeof(tag));
     331             :     LogWriteBytes(reinterpret_cast<const char*>(&s), sizeof(s));
     332           0 :   }
     333             : 
     334             :   FILE* ll_output_handle_;
     335             : };
     336             : 
     337             : const char LowLevelLogger::kLogExt[] = ".ll";
     338             : 
     339           0 : LowLevelLogger::LowLevelLogger(const char* name)
     340           0 :     : ll_output_handle_(NULL) {
     341             :   // Open the low-level log file.
     342           0 :   size_t len = strlen(name);
     343           0 :   ScopedVector<char> ll_name(static_cast<int>(len + sizeof(kLogExt)));
     344             :   MemCopy(ll_name.start(), name, len);
     345           0 :   MemCopy(ll_name.start() + len, kLogExt, sizeof(kLogExt));
     346             :   ll_output_handle_ =
     347           0 :       base::OS::FOpen(ll_name.start(), base::OS::LogFileOpenMode);
     348           0 :   setvbuf(ll_output_handle_, NULL, _IOLBF, 0);
     349             : 
     350             :   LogCodeInfo();
     351           0 : }
     352             : 
     353             : 
     354           0 : LowLevelLogger::~LowLevelLogger() {
     355           0 :   fclose(ll_output_handle_);
     356           0 :   ll_output_handle_ = NULL;
     357           0 : }
     358             : 
     359             : 
     360           0 : void LowLevelLogger::LogCodeInfo() {
     361             : #if V8_TARGET_ARCH_IA32
     362             :   const char arch[] = "ia32";
     363             : #elif V8_TARGET_ARCH_X64 && V8_TARGET_ARCH_64_BIT
     364           0 :   const char arch[] = "x64";
     365             : #elif V8_TARGET_ARCH_X64 && V8_TARGET_ARCH_32_BIT
     366             :   const char arch[] = "x32";
     367             : #elif V8_TARGET_ARCH_ARM
     368             :   const char arch[] = "arm";
     369             : #elif V8_TARGET_ARCH_PPC
     370             :   const char arch[] = "ppc";
     371             : #elif V8_TARGET_ARCH_MIPS
     372             :   const char arch[] = "mips";
     373             : #elif V8_TARGET_ARCH_X87
     374             :   const char arch[] = "x87";
     375             : #elif V8_TARGET_ARCH_ARM64
     376             :   const char arch[] = "arm64";
     377             : #elif V8_TARGET_ARCH_S390
     378             :   const char arch[] = "s390";
     379             : #else
     380             :   const char arch[] = "unknown";
     381             : #endif
     382             :   LogWriteBytes(arch, sizeof(arch));
     383           0 : }
     384             : 
     385           0 : void LowLevelLogger::LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo*,
     386             :                                        const char* name, int length) {
     387             :   CodeCreateStruct event;
     388           0 :   event.name_size = length;
     389           0 :   event.code_address = code->instruction_start();
     390           0 :   event.code_size = code->instruction_size();
     391           0 :   LogWriteStruct(event);
     392             :   LogWriteBytes(name, length);
     393             :   LogWriteBytes(
     394           0 :       reinterpret_cast<const char*>(code->instruction_start()),
     395           0 :       code->instruction_size());
     396           0 : }
     397             : 
     398           0 : void LowLevelLogger::CodeMoveEvent(AbstractCode* from, Address to) {
     399             :   CodeMoveStruct event;
     400           0 :   event.from_address = from->instruction_start();
     401           0 :   size_t header_size = from->instruction_start() - from->address();
     402           0 :   event.to_address = to + header_size;
     403           0 :   LogWriteStruct(event);
     404           0 : }
     405             : 
     406             : 
     407           0 : void LowLevelLogger::LogWriteBytes(const char* bytes, int size) {
     408           0 :   size_t rv = fwrite(bytes, 1, size, ll_output_handle_);
     409             :   DCHECK(static_cast<size_t>(size) == rv);
     410             :   USE(rv);
     411           0 : }
     412             : 
     413             : 
     414           0 : void LowLevelLogger::CodeMovingGCEvent() {
     415           0 :   const char tag = kCodeMovingGCTag;
     416             : 
     417             :   LogWriteBytes(&tag, sizeof(tag));
     418           0 : }
     419             : 
     420         117 : class JitLogger : public CodeEventLogger {
     421             :  public:
     422             :   explicit JitLogger(JitCodeEventHandler code_event_handler);
     423             : 
     424             :   void CodeMoveEvent(AbstractCode* from, Address to) override;
     425           4 :   void CodeDisableOptEvent(AbstractCode* code,
     426           4 :                            SharedFunctionInfo* shared) override {}
     427             :   void AddCodeLinePosInfoEvent(void* jit_handler_data, int pc_offset,
     428             :                                int position,
     429             :                                JitCodeEvent::PositionType position_type);
     430             : 
     431             :   void* StartCodePosInfoEvent();
     432             :   void EndCodePosInfoEvent(AbstractCode* code, void* jit_handler_data);
     433             : 
     434             :  private:
     435             :   void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
     436             :                          const char* name, int length) override;
     437             : 
     438             :   JitCodeEventHandler code_event_handler_;
     439             :   base::Mutex logger_mutex_;
     440             : };
     441             : 
     442             : 
     443          39 : JitLogger::JitLogger(JitCodeEventHandler code_event_handler)
     444          39 :     : code_event_handler_(code_event_handler) {
     445          39 : }
     446             : 
     447        8895 : void JitLogger::LogRecordedBuffer(AbstractCode* code,
     448             :                                   SharedFunctionInfo* shared, const char* name,
     449             :                                   int length) {
     450             :   JitCodeEvent event;
     451             :   memset(&event, 0, sizeof(event));
     452             :   event.type = JitCodeEvent::CODE_ADDED;
     453        8895 :   event.code_start = code->instruction_start();
     454        8895 :   event.code_len = code->instruction_size();
     455             :   Handle<SharedFunctionInfo> shared_function_handle;
     456       12121 :   if (shared && shared->script()->IsScript()) {
     457             :     shared_function_handle = Handle<SharedFunctionInfo>(shared);
     458             :   }
     459        8895 :   event.script = ToApiHandle<v8::UnboundScript>(shared_function_handle);
     460        8895 :   event.name.str = name;
     461        8895 :   event.name.len = length;
     462        8895 :   code_event_handler_(&event);
     463        8895 : }
     464             : 
     465         238 : void JitLogger::CodeMoveEvent(AbstractCode* from, Address to) {
     466         238 :   base::LockGuard<base::Mutex> guard(&logger_mutex_);
     467             : 
     468             :   JitCodeEvent event;
     469         238 :   event.type = JitCodeEvent::CODE_MOVED;
     470         238 :   event.code_start = from->instruction_start();
     471         238 :   event.code_len = from->instruction_size();
     472             : 
     473             :   // Calculate the header size.
     474         238 :   const size_t header_size = from->instruction_start() - from->address();
     475             : 
     476             :   // Calculate the new start address of the instructions.
     477         238 :   event.new_code_start = to + header_size;
     478             : 
     479         238 :   code_event_handler_(&event);
     480         238 : }
     481             : 
     482        4244 : void JitLogger::AddCodeLinePosInfoEvent(
     483             :     void* jit_handler_data,
     484             :     int pc_offset,
     485             :     int position,
     486             :     JitCodeEvent::PositionType position_type) {
     487             :   JitCodeEvent event;
     488             :   memset(&event, 0, sizeof(event));
     489        4244 :   event.type = JitCodeEvent::CODE_ADD_LINE_POS_INFO;
     490        4244 :   event.user_data = jit_handler_data;
     491        4244 :   event.line_info.offset = pc_offset;
     492        4244 :   event.line_info.pos = position;
     493        4244 :   event.line_info.position_type = position_type;
     494             : 
     495        4244 :   code_event_handler_(&event);
     496        4244 : }
     497             : 
     498             : 
     499         325 : void* JitLogger::StartCodePosInfoEvent() {
     500             :   JitCodeEvent event;
     501             :   memset(&event, 0, sizeof(event));
     502         325 :   event.type = JitCodeEvent::CODE_START_LINE_INFO_RECORDING;
     503             : 
     504         325 :   code_event_handler_(&event);
     505         325 :   return event.user_data;
     506             : }
     507             : 
     508         325 : void JitLogger::EndCodePosInfoEvent(AbstractCode* code,
     509             :                                     void* jit_handler_data) {
     510             :   JitCodeEvent event;
     511             :   memset(&event, 0, sizeof(event));
     512         325 :   event.type = JitCodeEvent::CODE_END_LINE_INFO_RECORDING;
     513         325 :   event.code_start = code->instruction_start();
     514         325 :   event.user_data = jit_handler_data;
     515             : 
     516         325 :   code_event_handler_(&event);
     517         325 : }
     518             : 
     519             : 
     520             : // TODO(lpy): Keeping sampling thread inside V8 is a workaround currently,
     521             : // the reason is to reduce code duplication during migration to sampler library,
     522             : // sampling thread, as well as the sampler, will be moved to D8 eventually.
     523       59285 : class SamplingThread : public base::Thread {
     524             :  public:
     525             :   static const int kSamplingThreadStackSize = 64 * KB;
     526             : 
     527             :   SamplingThread(sampler::Sampler* sampler, int interval_microseconds)
     528             :       : base::Thread(
     529             :             base::Thread::Options("SamplingThread", kSamplingThreadStackSize)),
     530             :         sampler_(sampler),
     531       60782 :         interval_microseconds_(interval_microseconds) {}
     532           0 :   void Run() override {
     533           0 :     while (sampler_->IsProfiling()) {
     534           0 :       sampler_->DoSample();
     535             :       base::OS::Sleep(
     536           0 :           base::TimeDelta::FromMicroseconds(interval_microseconds_));
     537             :     }
     538           0 :   }
     539             : 
     540             :  private:
     541             :   sampler::Sampler* sampler_;
     542             :   const int interval_microseconds_;
     543             : };
     544             : 
     545             : 
     546             : // The Profiler samples pc and sp values for the main thread.
     547             : // Each sample is appended to a circular buffer.
     548             : // An independent thread removes data and writes it to the log.
     549             : // This design minimizes the time spent in the sampler.
     550             : //
     551           0 : class Profiler: public base::Thread {
     552             :  public:
     553             :   explicit Profiler(Isolate* isolate);
     554             :   void Engage();
     555             :   void Disengage();
     556             : 
     557             :   // Inserts collected profiling data into buffer.
     558           0 :   void Insert(v8::TickSample* sample) {
     559           0 :     if (paused_)
     560           0 :       return;
     561             : 
     562           0 :     if (Succ(head_) == static_cast<int>(base::NoBarrier_Load(&tail_))) {
     563           0 :       overflow_ = true;
     564             :     } else {
     565           0 :       buffer_[head_] = *sample;
     566           0 :       head_ = Succ(head_);
     567           0 :       buffer_semaphore_.Signal();  // Tell we have an element.
     568             :     }
     569             :   }
     570             : 
     571             :   virtual void Run();
     572             : 
     573             :   // Pause and Resume TickSample data collection.
     574           0 :   void pause() { paused_ = true; }
     575           0 :   void resume() { paused_ = false; }
     576             : 
     577             :  private:
     578             :   // Waits for a signal and removes profiling data.
     579           0 :   bool Remove(v8::TickSample* sample) {
     580           0 :     buffer_semaphore_.Wait();  // Wait for an element.
     581           0 :     *sample = buffer_[base::NoBarrier_Load(&tail_)];
     582           0 :     bool result = overflow_;
     583             :     base::NoBarrier_Store(&tail_, static_cast<base::Atomic32>(
     584             :                                       Succ(base::NoBarrier_Load(&tail_))));
     585           0 :     overflow_ = false;
     586           0 :     return result;
     587             :   }
     588             : 
     589             :   // Returns the next index in the cyclic buffer.
     590           0 :   int Succ(int index) { return (index + 1) % kBufferSize; }
     591             : 
     592             :   Isolate* isolate_;
     593             :   // Cyclic buffer for communicating profiling samples
     594             :   // between the signal handler and the worker thread.
     595             :   static const int kBufferSize = 128;
     596             :   v8::TickSample buffer_[kBufferSize];  // Buffer storage.
     597             :   int head_;  // Index to the buffer head.
     598             :   base::Atomic32 tail_;             // Index to the buffer tail.
     599             :   bool overflow_;  // Tell whether a buffer overflow has occurred.
     600             :   // Sempahore used for buffer synchronization.
     601             :   base::Semaphore buffer_semaphore_;
     602             : 
     603             :   // Tells whether profiler is engaged, that is, processing thread is stated.
     604             :   bool engaged_;
     605             : 
     606             :   // Tells whether worker thread should continue running.
     607             :   base::Atomic32 running_;
     608             : 
     609             :   // Tells whether we are currently recording tick samples.
     610             :   bool paused_;
     611             : };
     612             : 
     613             : 
     614             : //
     615             : // Ticker used to provide ticks to the profiler and the sliding state
     616             : // window.
     617             : //
     618             : class Ticker: public sampler::Sampler {
     619             :  public:
     620       60782 :   Ticker(Isolate* isolate, int interval_microseconds)
     621             :       : sampler::Sampler(reinterpret_cast<v8::Isolate*>(isolate)),
     622             :         profiler_(nullptr),
     623      121564 :         sampling_thread_(new SamplingThread(this, interval_microseconds)) {}
     624             : 
     625      177855 :   ~Ticker() {
     626       59285 :     if (IsActive()) Stop();
     627       59285 :     delete sampling_thread_;
     628      118570 :   }
     629             : 
     630           0 :   void SetProfiler(Profiler* profiler) {
     631             :     DCHECK(profiler_ == nullptr);
     632           0 :     profiler_ = profiler;
     633           0 :     IncreaseProfilingDepth();
     634           0 :     if (!IsActive()) Start();
     635           0 :     sampling_thread_->StartSynchronously();
     636           0 :   }
     637             : 
     638           0 :   void ClearProfiler() {
     639           0 :     profiler_ = nullptr;
     640           0 :     if (IsActive()) Stop();
     641           0 :     DecreaseProfilingDepth();
     642           0 :     sampling_thread_->Join();
     643           0 :   }
     644             : 
     645           0 :   void SampleStack(const v8::RegisterState& state) override {
     646           0 :     if (!profiler_) return;
     647           0 :     Isolate* isolate = reinterpret_cast<Isolate*>(this->isolate());
     648             :     TickSample sample;
     649           0 :     sample.Init(isolate, state, TickSample::kIncludeCEntryFrame, true);
     650           0 :     profiler_->Insert(&sample);
     651             :   }
     652             : 
     653             :  private:
     654             :   Profiler* profiler_;
     655             :   SamplingThread* sampling_thread_;
     656             : };
     657             : 
     658             : 
     659             : //
     660             : // Profiler implementation.
     661             : //
     662           0 : Profiler::Profiler(Isolate* isolate)
     663             :     : base::Thread(Options("v8:Profiler")),
     664             :       isolate_(isolate),
     665             :       head_(0),
     666             :       overflow_(false),
     667             :       buffer_semaphore_(0),
     668             :       engaged_(false),
     669           0 :       paused_(false) {
     670           0 :   base::NoBarrier_Store(&tail_, 0);
     671           0 :   base::NoBarrier_Store(&running_, 0);
     672           0 : }
     673             : 
     674             : 
     675           0 : void Profiler::Engage() {
     676           0 :   if (engaged_) return;
     677           0 :   engaged_ = true;
     678             : 
     679             :   std::vector<base::OS::SharedLibraryAddress> addresses =
     680           0 :       base::OS::GetSharedLibraryAddresses();
     681           0 :   for (size_t i = 0; i < addresses.size(); ++i) {
     682           0 :     LOG(isolate_,
     683             :         SharedLibraryEvent(addresses[i].library_path, addresses[i].start,
     684             :                            addresses[i].end, addresses[i].aslr_slide));
     685             :   }
     686             : 
     687             :   // Start thread processing the profiler buffer.
     688           0 :   base::NoBarrier_Store(&running_, 1);
     689           0 :   Start();
     690             : 
     691             :   // Register to get ticks.
     692           0 :   Logger* logger = isolate_->logger();
     693           0 :   logger->ticker_->SetProfiler(this);
     694             : 
     695           0 :   logger->ProfilerBeginEvent();
     696             : }
     697             : 
     698             : 
     699           0 : void Profiler::Disengage() {
     700           0 :   if (!engaged_) return;
     701             : 
     702             :   // Stop receiving ticks.
     703           0 :   isolate_->logger()->ticker_->ClearProfiler();
     704             : 
     705             :   // Terminate the worker thread by setting running_ to false,
     706             :   // inserting a fake element in the queue and then wait for
     707             :   // the thread to terminate.
     708           0 :   base::NoBarrier_Store(&running_, 0);
     709             :   v8::TickSample sample;
     710             :   // Reset 'paused_' flag, otherwise semaphore may not be signalled.
     711             :   resume();
     712           0 :   Insert(&sample);
     713           0 :   Join();
     714             : 
     715           0 :   LOG(isolate_, UncheckedStringEvent("profiler", "end"));
     716             : }
     717             : 
     718             : 
     719           0 : void Profiler::Run() {
     720             :   v8::TickSample sample;
     721           0 :   bool overflow = Remove(&sample);
     722           0 :   while (base::NoBarrier_Load(&running_)) {
     723           0 :     LOG(isolate_, TickEvent(&sample, overflow));
     724           0 :     overflow = Remove(&sample);
     725             :   }
     726           0 : }
     727             : 
     728             : 
     729             : //
     730             : // Logger class implementation.
     731             : //
     732             : 
     733       60782 : Logger::Logger(Isolate* isolate)
     734             :     : isolate_(isolate),
     735             :       ticker_(NULL),
     736             :       profiler_(NULL),
     737             :       log_events_(NULL),
     738             :       is_logging_(false),
     739       60782 :       log_(new Log(this)),
     740             :       perf_basic_logger_(NULL),
     741             :       perf_jit_logger_(NULL),
     742             :       ll_logger_(NULL),
     743             :       jit_logger_(NULL),
     744             :       listeners_(5),
     745      243128 :       is_initialized_(false) {}
     746             : 
     747      118570 : Logger::~Logger() {
     748      118570 :   delete log_;
     749      118570 : }
     750             : 
     751         296 : void Logger::addCodeEventListener(CodeEventListener* listener) {
     752        1306 :   bool result = isolate_->code_event_dispatcher()->AddListener(listener);
     753             :   USE(result);
     754             :   DCHECK(result);
     755         296 : }
     756             : 
     757         290 : void Logger::removeCodeEventListener(CodeEventListener* listener) {
     758        1722 :   isolate_->code_event_dispatcher()->RemoveListener(listener);
     759         290 : }
     760             : 
     761           0 : void Logger::ProfilerBeginEvent() {
     762           0 :   if (!log_->IsEnabled()) return;
     763           0 :   Log::MessageBuilder msg(log_);
     764           0 :   msg.Append("profiler,\"begin\",%d", FLAG_prof_sampling_interval);
     765           0 :   msg.WriteToLogFile();
     766             : }
     767             : 
     768             : 
     769           0 : void Logger::StringEvent(const char* name, const char* value) {
     770           0 :   if (FLAG_log) UncheckedStringEvent(name, value);
     771           0 : }
     772             : 
     773             : 
     774           0 : void Logger::UncheckedStringEvent(const char* name, const char* value) {
     775           0 :   if (!log_->IsEnabled()) return;
     776           0 :   Log::MessageBuilder msg(log_);
     777           0 :   msg.Append("%s,\"%s\"", name, value);
     778           0 :   msg.WriteToLogFile();
     779             : }
     780             : 
     781             : 
     782           0 : void Logger::IntEvent(const char* name, int value) {
     783           0 :   if (FLAG_log) UncheckedIntEvent(name, value);
     784           0 : }
     785             : 
     786             : 
     787          48 : void Logger::IntPtrTEvent(const char* name, intptr_t value) {
     788          48 :   if (FLAG_log) UncheckedIntPtrTEvent(name, value);
     789          48 : }
     790             : 
     791             : 
     792           0 : void Logger::UncheckedIntEvent(const char* name, int value) {
     793           0 :   if (!log_->IsEnabled()) return;
     794           0 :   Log::MessageBuilder msg(log_);
     795           0 :   msg.Append("%s,%d", name, value);
     796           0 :   msg.WriteToLogFile();
     797             : }
     798             : 
     799             : 
     800          48 : void Logger::UncheckedIntPtrTEvent(const char* name, intptr_t value) {
     801          96 :   if (!log_->IsEnabled()) return;
     802          48 :   Log::MessageBuilder msg(log_);
     803          48 :   msg.Append("%s,%" V8PRIdPTR, name, value);
     804          48 :   msg.WriteToLogFile();
     805             : }
     806             : 
     807             : 
     808           0 : void Logger::HandleEvent(const char* name, Object** location) {
     809           0 :   if (!log_->IsEnabled() || !FLAG_log_handles) return;
     810           0 :   Log::MessageBuilder msg(log_);
     811           0 :   msg.Append("%s,%p", name, static_cast<void*>(location));
     812           0 :   msg.WriteToLogFile();
     813             : }
     814             : 
     815             : 
     816             : // ApiEvent is private so all the calls come from the Logger class.  It is the
     817             : // caller's responsibility to ensure that log is enabled and that
     818             : // FLAG_log_api is true.
     819           0 : void Logger::ApiEvent(const char* format, ...) {
     820             :   DCHECK(log_->IsEnabled() && FLAG_log_api);
     821           0 :   Log::MessageBuilder msg(log_);
     822             :   va_list ap;
     823           0 :   va_start(ap, format);
     824           0 :   msg.AppendVA(format, ap);
     825           0 :   va_end(ap);
     826           0 :   msg.WriteToLogFile();
     827           0 : }
     828             : 
     829             : 
     830           0 : void Logger::ApiSecurityCheck() {
     831           0 :   if (!log_->IsEnabled() || !FLAG_log_api) return;
     832           0 :   ApiEvent("api,check-security");
     833             : }
     834             : 
     835           0 : void Logger::SharedLibraryEvent(const std::string& library_path,
     836             :                                 uintptr_t start, uintptr_t end,
     837             :                                 intptr_t aslr_slide) {
     838           0 :   if (!log_->IsEnabled() || !FLAG_prof_cpp) return;
     839           0 :   Log::MessageBuilder msg(log_);
     840             :   msg.Append("shared-library,\"%s\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR
     841             :              ",%" V8PRIdPTR,
     842           0 :              library_path.c_str(), start, end, aslr_slide);
     843           0 :   msg.WriteToLogFile();
     844             : }
     845             : 
     846           0 : void Logger::CodeDeoptEvent(Code* code, DeoptKind kind, Address pc,
     847             :                             int fp_to_sp_delta) {
     848           0 :   if (!log_->IsEnabled()) return;
     849           0 :   Deoptimizer::DeoptInfo info = Deoptimizer::GetDeoptInfo(code, pc);
     850           0 :   Log::MessageBuilder msg(log_);
     851             :   int since_epoch = timer_.IsStarted()
     852             :                         ? static_cast<int>(timer_.Elapsed().InMicroseconds())
     853           0 :                         : -1;
     854           0 :   msg.Append("code-deopt,%d,%d,", since_epoch, code->CodeSize());
     855           0 :   msg.AppendAddress(code->address());
     856             : 
     857             :   // Deoptimization position.
     858           0 :   std::ostringstream deopt_location;
     859             :   int inlining_id = -1;
     860             :   int script_offset = -1;
     861           0 :   if (info.position.IsKnown()) {
     862           0 :     info.position.Print(deopt_location, code);
     863             :     inlining_id = info.position.InliningId();
     864             :     script_offset = info.position.ScriptOffset();
     865             :   } else {
     866           0 :     deopt_location << "<unknown>";
     867             :   }
     868           0 :   msg.Append(",%d,%d,", inlining_id, script_offset);
     869           0 :   switch (kind) {
     870             :     case kLazy:
     871           0 :       msg.Append("\"lazy\",");
     872           0 :       break;
     873             :     case kSoft:
     874           0 :       msg.Append("\"soft\",");
     875           0 :       break;
     876             :     case kEager:
     877           0 :       msg.Append("\"eager\",");
     878           0 :       break;
     879             :   }
     880           0 :   msg.AppendDoubleQuotedString(deopt_location.str().c_str());
     881           0 :   msg.Append(",");
     882           0 :   msg.AppendDoubleQuotedString(DeoptimizeReasonToString(info.deopt_reason));
     883           0 :   msg.WriteToLogFile();
     884             : }
     885             : 
     886             : 
     887           0 : void Logger::CurrentTimeEvent() {
     888           0 :   if (!log_->IsEnabled()) return;
     889             :   DCHECK(FLAG_log_timer_events || FLAG_prof_cpp);
     890           0 :   Log::MessageBuilder msg(log_);
     891           0 :   int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());
     892           0 :   msg.Append("current-time,%d", since_epoch);
     893           0 :   msg.WriteToLogFile();
     894             : }
     895             : 
     896             : 
     897           0 : void Logger::TimerEvent(Logger::StartEnd se, const char* name) {
     898           0 :   if (!log_->IsEnabled()) return;
     899             :   DCHECK(FLAG_log_internal_timer_events);
     900           0 :   Log::MessageBuilder msg(log_);
     901           0 :   int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());
     902             :   const char* format = (se == START) ? "timer-event-start,\"%s\",%ld"
     903           0 :                                      : "timer-event-end,\"%s\",%ld";
     904           0 :   msg.Append(format, name, since_epoch);
     905           0 :   msg.WriteToLogFile();
     906             : }
     907             : 
     908             : 
     909           0 : void Logger::EnterExternal(Isolate* isolate) {
     910           0 :   LOG(isolate, TimerEvent(START, TimerEventExternal::name()));
     911             :   DCHECK(isolate->current_vm_state() == JS);
     912             :   isolate->set_current_vm_state(EXTERNAL);
     913           0 : }
     914             : 
     915             : 
     916           0 : void Logger::LeaveExternal(Isolate* isolate) {
     917           0 :   LOG(isolate, TimerEvent(END, TimerEventExternal::name()));
     918             :   DCHECK(isolate->current_vm_state() == EXTERNAL);
     919             :   isolate->set_current_vm_state(JS);
     920           0 : }
     921             : 
     922             : // Instantiate template methods.
     923             : #define V(TimerName, expose)                                           \
     924             :   template void TimerEventScope<TimerEvent##TimerName>::LogTimerEvent( \
     925             :       Logger::StartEnd se);
     926             : TIMER_EVENTS_LIST(V)
     927             : #undef V
     928             : 
     929         336 : void Logger::ApiNamedPropertyAccess(const char* tag,
     930             :                                     JSObject* holder,
     931             :                                     Object* name) {
     932             :   DCHECK(name->IsName());
     933        1008 :   if (!log_->IsEnabled() || !FLAG_log_api) return;
     934           0 :   String* class_name_obj = holder->class_name();
     935             :   std::unique_ptr<char[]> class_name =
     936           0 :       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
     937           0 :   if (name->IsString()) {
     938             :     std::unique_ptr<char[]> property_name =
     939           0 :         String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
     940             :     ApiEvent("api,%s,\"%s\",\"%s\"", tag, class_name.get(),
     941           0 :              property_name.get());
     942             :   } else {
     943             :     Symbol* symbol = Symbol::cast(name);
     944             :     uint32_t hash = symbol->Hash();
     945           0 :     if (symbol->name()->IsUndefined(symbol->GetIsolate())) {
     946           0 :       ApiEvent("api,%s,\"%s\",symbol(hash %x)", tag, class_name.get(), hash);
     947             :     } else {
     948             :       std::unique_ptr<char[]> str =
     949             :           String::cast(symbol->name())
     950           0 :               ->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
     951             :       ApiEvent("api,%s,\"%s\",symbol(\"%s\" hash %x)", tag, class_name.get(),
     952           0 :                str.get(), hash);
     953             :     }
     954             :   }
     955             : }
     956             : 
     957           0 : void Logger::ApiIndexedPropertyAccess(const char* tag,
     958             :                                       JSObject* holder,
     959             :                                       uint32_t index) {
     960           0 :   if (!log_->IsEnabled() || !FLAG_log_api) return;
     961           0 :   String* class_name_obj = holder->class_name();
     962             :   std::unique_ptr<char[]> class_name =
     963           0 :       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
     964           0 :   ApiEvent("api,%s,\"%s\",%u", tag, class_name.get(), index);
     965             : }
     966             : 
     967             : 
     968           0 : void Logger::ApiObjectAccess(const char* tag, JSObject* object) {
     969           0 :   if (!log_->IsEnabled() || !FLAG_log_api) return;
     970           0 :   String* class_name_obj = object->class_name();
     971             :   std::unique_ptr<char[]> class_name =
     972           0 :       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
     973           0 :   ApiEvent("api,%s,\"%s\"", tag, class_name.get());
     974             : }
     975             : 
     976             : 
     977         522 : void Logger::ApiEntryCall(const char* name) {
     978        1566 :   if (!log_->IsEnabled() || !FLAG_log_api) return;
     979           0 :   ApiEvent("api,%s", name);
     980             : }
     981             : 
     982             : 
     983         318 : void Logger::NewEvent(const char* name, void* object, size_t size) {
     984         636 :   if (!log_->IsEnabled() || !FLAG_log) return;
     985         318 :   Log::MessageBuilder msg(log_);
     986         318 :   msg.Append("new,%s,%p,%u", name, object, static_cast<unsigned int>(size));
     987         318 :   msg.WriteToLogFile();
     988             : }
     989             : 
     990             : 
     991         294 : void Logger::DeleteEvent(const char* name, void* object) {
     992         882 :   if (!log_->IsEnabled() || !FLAG_log) return;
     993           0 :   Log::MessageBuilder msg(log_);
     994           0 :   msg.Append("delete,%s,%p", name, object);
     995           0 :   msg.WriteToLogFile();
     996             : }
     997             : 
     998             : 
     999         900 : void Logger::CallbackEventInternal(const char* prefix, Name* name,
    1000             :                                    Address entry_point) {
    1001        1800 :   if (!FLAG_log_code || !log_->IsEnabled()) return;
    1002         900 :   Log::MessageBuilder msg(log_);
    1003             :   msg.Append("%s,%s,-2,",
    1004             :              kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT],
    1005         900 :              kLogEventsNames[CodeEventListener::CALLBACK_TAG]);
    1006             :   int timestamp = timer_.IsStarted()
    1007             :                       ? static_cast<int>(timer_.Elapsed().InMicroseconds())
    1008         900 :                       : -1;
    1009         900 :   msg.Append("%d,", timestamp);
    1010         900 :   msg.AppendAddress(entry_point);
    1011         900 :   if (name->IsString()) {
    1012             :     std::unique_ptr<char[]> str =
    1013         888 :         String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    1014         888 :     msg.Append(",1,\"%s%s\"", prefix, str.get());
    1015             :   } else {
    1016             :     Symbol* symbol = Symbol::cast(name);
    1017          12 :     if (symbol->name()->IsUndefined(symbol->GetIsolate())) {
    1018           0 :       msg.Append(",1,symbol(hash %x)", symbol->Hash());
    1019             :     } else {
    1020             :       std::unique_ptr<char[]> str =
    1021             :           String::cast(symbol->name())
    1022          12 :               ->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    1023             :       msg.Append(",1,symbol(\"%s%s\" hash %x)", prefix, str.get(),
    1024          12 :                  symbol->Hash());
    1025             :     }
    1026             :   }
    1027         900 :   msg.WriteToLogFile();
    1028             : }
    1029             : 
    1030             : 
    1031         198 : void Logger::CallbackEvent(Name* name, Address entry_point) {
    1032         198 :   CallbackEventInternal("", name, entry_point);
    1033         198 : }
    1034             : 
    1035             : 
    1036         354 : void Logger::GetterCallbackEvent(Name* name, Address entry_point) {
    1037         354 :   CallbackEventInternal("get ", name, entry_point);
    1038         354 : }
    1039             : 
    1040             : 
    1041         348 : void Logger::SetterCallbackEvent(Name* name, Address entry_point) {
    1042         348 :   CallbackEventInternal("set ", name, entry_point);
    1043         348 : }
    1044             : 
    1045             : namespace {
    1046             : 
    1047       48753 : void AppendCodeCreateHeader(Log::MessageBuilder* msg,
    1048             :                             CodeEventListener::LogEventsAndTags tag,
    1049             :                             AbstractCode* code, base::ElapsedTimer* timer) {
    1050             :   DCHECK(msg);
    1051             :   msg->Append("%s,%s,%d,",
    1052             :               kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT],
    1053       48753 :               kLogEventsNames[tag], code->kind());
    1054             :   int timestamp = timer->IsStarted()
    1055             :                       ? static_cast<int>(timer->Elapsed().InMicroseconds())
    1056       48753 :                       : -1;
    1057       48753 :   msg->Append("%d,", timestamp);
    1058       48753 :   msg->AppendAddress(code->address());
    1059       48753 :   msg->Append(",%d,", code->ExecutableSize());
    1060       48753 : }
    1061             : 
    1062             : }  // namespace
    1063             : 
    1064       32939 : void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    1065             :                              AbstractCode* code, const char* comment) {
    1066       32939 :   if (!is_logging_code_events()) return;
    1067       65878 :   if (!FLAG_log_code || !log_->IsEnabled()) return;
    1068       32939 :   Log::MessageBuilder msg(log_);
    1069       32939 :   AppendCodeCreateHeader(&msg, tag, code, &timer_);
    1070       32939 :   msg.AppendDoubleQuotedString(comment);
    1071       32939 :   msg.WriteToLogFile();
    1072             : }
    1073             : 
    1074           0 : void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    1075             :                              AbstractCode* code, Name* name) {
    1076           0 :   if (!is_logging_code_events()) return;
    1077           0 :   if (!FLAG_log_code || !log_->IsEnabled()) return;
    1078           0 :   Log::MessageBuilder msg(log_);
    1079           0 :   AppendCodeCreateHeader(&msg, tag, code, &timer_);
    1080           0 :   if (name->IsString()) {
    1081           0 :     msg.Append('"');
    1082           0 :     msg.AppendDetailed(String::cast(name), false);
    1083           0 :     msg.Append('"');
    1084             :   } else {
    1085           0 :     msg.AppendSymbolName(Symbol::cast(name));
    1086             :   }
    1087           0 :   msg.WriteToLogFile();
    1088             : }
    1089             : 
    1090       15732 : void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    1091             :                              AbstractCode* code, SharedFunctionInfo* shared,
    1092             :                              Name* name) {
    1093       15732 :   if (!is_logging_code_events()) return;
    1094       31464 :   if (!FLAG_log_code || !log_->IsEnabled()) return;
    1095       15732 :   if (code == AbstractCode::cast(
    1096       15732 :                   isolate_->builtins()->builtin(Builtins::kCompileLazy))) {
    1097             :     return;
    1098             :   }
    1099             : 
    1100       15732 :   Log::MessageBuilder msg(log_);
    1101       15732 :   AppendCodeCreateHeader(&msg, tag, code, &timer_);
    1102       15732 :   if (name->IsString()) {
    1103             :     std::unique_ptr<char[]> str =
    1104       15732 :         String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    1105       15732 :     msg.Append("\"%s\"", str.get());
    1106             :   } else {
    1107           0 :     msg.AppendSymbolName(Symbol::cast(name));
    1108             :   }
    1109       15732 :   msg.Append(',');
    1110       15732 :   msg.AppendAddress(shared->address());
    1111       15732 :   msg.Append(",%s", ComputeMarker(shared, code));
    1112       15732 :   msg.WriteToLogFile();
    1113             : }
    1114             : 
    1115             : 
    1116             : // Although, it is possible to extract source and line from
    1117             : // the SharedFunctionInfo object, we left it to caller
    1118             : // to leave logging functions free from heap allocations.
    1119          82 : void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    1120             :                              AbstractCode* code, SharedFunctionInfo* shared,
    1121             :                              Name* source, int line, int column) {
    1122          82 :   if (!is_logging_code_events()) return;
    1123         164 :   if (!FLAG_log_code || !log_->IsEnabled()) return;
    1124          82 :   Log::MessageBuilder msg(log_);
    1125          82 :   AppendCodeCreateHeader(&msg, tag, code, &timer_);
    1126             :   std::unique_ptr<char[]> name =
    1127          82 :       shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    1128          82 :   msg.Append("\"%s ", name.get());
    1129          82 :   if (source->IsString()) {
    1130             :     std::unique_ptr<char[]> sourcestr = String::cast(source)->ToCString(
    1131          82 :         DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    1132          82 :     msg.Append("%s", sourcestr.get());
    1133             :   } else {
    1134           0 :     msg.AppendSymbolName(Symbol::cast(source));
    1135             :   }
    1136          82 :   msg.Append(":%d:%d\",", line, column);
    1137          82 :   msg.AppendAddress(shared->address());
    1138          82 :   msg.Append(",%s", ComputeMarker(shared, code));
    1139          82 :   msg.WriteToLogFile();
    1140             : }
    1141             : 
    1142           0 : void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    1143             :                              AbstractCode* code, int args_count) {
    1144           0 :   if (!is_logging_code_events()) return;
    1145           0 :   if (!FLAG_log_code || !log_->IsEnabled()) return;
    1146           0 :   Log::MessageBuilder msg(log_);
    1147           0 :   AppendCodeCreateHeader(&msg, tag, code, &timer_);
    1148           0 :   msg.Append("\"args_count: %d\"", args_count);
    1149           0 :   msg.WriteToLogFile();
    1150             : }
    1151             : 
    1152           0 : void Logger::CodeDisableOptEvent(AbstractCode* code,
    1153             :                                  SharedFunctionInfo* shared) {
    1154           0 :   if (!is_logging_code_events()) return;
    1155           0 :   if (!FLAG_log_code || !log_->IsEnabled()) return;
    1156           0 :   Log::MessageBuilder msg(log_);
    1157           0 :   msg.Append("%s,", kLogEventsNames[CodeEventListener::CODE_DISABLE_OPT_EVENT]);
    1158             :   std::unique_ptr<char[]> name =
    1159           0 :       shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
    1160           0 :   msg.Append("\"%s\",", name.get());
    1161           0 :   msg.Append("\"%s\"", GetBailoutReason(shared->disable_optimization_reason()));
    1162           0 :   msg.WriteToLogFile();
    1163             : }
    1164             : 
    1165             : 
    1166           0 : void Logger::CodeMovingGCEvent() {
    1167           0 :   if (!is_logging_code_events()) return;
    1168           0 :   if (!log_->IsEnabled() || !FLAG_ll_prof) return;
    1169           0 :   base::OS::SignalCodeMovingGC();
    1170             : }
    1171             : 
    1172           0 : void Logger::RegExpCodeCreateEvent(AbstractCode* code, String* source) {
    1173           0 :   if (!is_logging_code_events()) return;
    1174           0 :   if (!FLAG_log_code || !log_->IsEnabled()) return;
    1175           0 :   Log::MessageBuilder msg(log_);
    1176           0 :   AppendCodeCreateHeader(&msg, CodeEventListener::REG_EXP_TAG, code, &timer_);
    1177           0 :   msg.Append('"');
    1178           0 :   msg.AppendDetailed(source, false);
    1179           0 :   msg.Append('"');
    1180           0 :   msg.WriteToLogFile();
    1181             : }
    1182             : 
    1183           0 : void Logger::CodeMoveEvent(AbstractCode* from, Address to) {
    1184           0 :   if (!is_logging_code_events()) return;
    1185           0 :   MoveEventInternal(CodeEventListener::CODE_MOVE_EVENT, from->address(), to);
    1186             : }
    1187             : 
    1188         349 : void Logger::CodeLinePosInfoRecordEvent(AbstractCode* code,
    1189             :                                         ByteArray* source_position_table) {
    1190         349 :   if (jit_logger_) {
    1191         325 :     void* jit_handler_data = jit_logger_->StartCodePosInfoEvent();
    1192        3895 :     for (SourcePositionTableIterator iter(source_position_table); !iter.done();
    1193        3245 :          iter.Advance()) {
    1194        3245 :       if (iter.is_statement()) {
    1195             :         jit_logger_->AddCodeLinePosInfoEvent(
    1196             :             jit_handler_data, iter.code_offset(),
    1197         999 :             iter.source_position().ScriptOffset(),
    1198         999 :             JitCodeEvent::STATEMENT_POSITION);
    1199             :       }
    1200             :       jit_logger_->AddCodeLinePosInfoEvent(
    1201             :           jit_handler_data, iter.code_offset(),
    1202        6490 :           iter.source_position().ScriptOffset(), JitCodeEvent::POSITION);
    1203             :     }
    1204         325 :     jit_logger_->EndCodePosInfoEvent(code, jit_handler_data);
    1205             :   }
    1206         349 : }
    1207             : 
    1208           0 : void Logger::CodeNameEvent(Address addr, int pos, const char* code_name) {
    1209           0 :   if (code_name == NULL) return;  // Not a code object.
    1210           0 :   Log::MessageBuilder msg(log_);
    1211             :   msg.Append("%s,%d,",
    1212           0 :              kLogEventsNames[CodeEventListener::SNAPSHOT_CODE_NAME_EVENT], pos);
    1213           0 :   msg.AppendDoubleQuotedString(code_name);
    1214           0 :   msg.WriteToLogFile();
    1215             : }
    1216             : 
    1217             : 
    1218        1413 : void Logger::SharedFunctionInfoMoveEvent(Address from, Address to) {
    1219        2826 :   if (!is_logging_code_events()) return;
    1220        1413 :   MoveEventInternal(CodeEventListener::SHARED_FUNC_MOVE_EVENT, from, to);
    1221             : }
    1222             : 
    1223        1413 : void Logger::MoveEventInternal(CodeEventListener::LogEventsAndTags event,
    1224             :                                Address from, Address to) {
    1225        2826 :   if (!FLAG_log_code || !log_->IsEnabled()) return;
    1226           0 :   Log::MessageBuilder msg(log_);
    1227           0 :   msg.Append("%s,", kLogEventsNames[event]);
    1228           0 :   msg.AppendAddress(from);
    1229           0 :   msg.Append(',');
    1230           0 :   msg.AppendAddress(to);
    1231           0 :   msg.WriteToLogFile();
    1232             : }
    1233             : 
    1234             : 
    1235           0 : void Logger::ResourceEvent(const char* name, const char* tag) {
    1236           0 :   if (!log_->IsEnabled() || !FLAG_log) return;
    1237           0 :   Log::MessageBuilder msg(log_);
    1238           0 :   msg.Append("%s,%s,", name, tag);
    1239             : 
    1240             :   uint32_t sec, usec;
    1241           0 :   if (base::OS::GetUserTime(&sec, &usec) != -1) {
    1242           0 :     msg.Append("%d,%d,", sec, usec);
    1243             :   }
    1244           0 :   msg.Append("%.0f", base::OS::TimeCurrentMillis());
    1245           0 :   msg.WriteToLogFile();
    1246             : }
    1247             : 
    1248             : 
    1249           0 : void Logger::SuspectReadEvent(Name* name, Object* obj) {
    1250           0 :   if (!log_->IsEnabled() || !FLAG_log_suspect) return;
    1251           0 :   Log::MessageBuilder msg(log_);
    1252             :   String* class_name = obj->IsJSObject()
    1253             :                        ? JSObject::cast(obj)->class_name()
    1254           0 :                        : isolate_->heap()->empty_string();
    1255           0 :   msg.Append("suspect-read,");
    1256           0 :   msg.Append(class_name);
    1257           0 :   msg.Append(',');
    1258           0 :   if (name->IsString()) {
    1259           0 :     msg.Append('"');
    1260           0 :     msg.Append(String::cast(name));
    1261           0 :     msg.Append('"');
    1262             :   } else {
    1263           0 :     msg.AppendSymbolName(Symbol::cast(name));
    1264             :   }
    1265           0 :   msg.WriteToLogFile();
    1266             : }
    1267             : 
    1268             : 
    1269           0 : void Logger::HeapSampleBeginEvent(const char* space, const char* kind) {
    1270           0 :   if (!log_->IsEnabled() || !FLAG_log_gc) return;
    1271           0 :   Log::MessageBuilder msg(log_);
    1272             :   // Using non-relative system time in order to be able to synchronize with
    1273             :   // external memory profiling events (e.g. DOM memory size).
    1274             :   msg.Append("heap-sample-begin,\"%s\",\"%s\",%.0f", space, kind,
    1275           0 :              base::OS::TimeCurrentMillis());
    1276           0 :   msg.WriteToLogFile();
    1277             : }
    1278             : 
    1279             : 
    1280           0 : void Logger::HeapSampleEndEvent(const char* space, const char* kind) {
    1281           0 :   if (!log_->IsEnabled() || !FLAG_log_gc) return;
    1282           0 :   Log::MessageBuilder msg(log_);
    1283           0 :   msg.Append("heap-sample-end,\"%s\",\"%s\"", space, kind);
    1284           0 :   msg.WriteToLogFile();
    1285             : }
    1286             : 
    1287             : 
    1288           0 : void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) {
    1289           0 :   if (!log_->IsEnabled() || !FLAG_log_gc) return;
    1290           0 :   Log::MessageBuilder msg(log_);
    1291           0 :   msg.Append("heap-sample-item,%s,%d,%d", type, number, bytes);
    1292           0 :   msg.WriteToLogFile();
    1293             : }
    1294             : 
    1295             : 
    1296           0 : void Logger::RuntimeCallTimerEvent() {
    1297           0 :   RuntimeCallStats* stats = isolate_->counters()->runtime_call_stats();
    1298           0 :   RuntimeCallCounter* counter = stats->current_counter();
    1299           0 :   if (counter == nullptr) return;
    1300           0 :   Log::MessageBuilder msg(log_);
    1301           0 :   msg.Append("active-runtime-timer,");
    1302           0 :   msg.AppendDoubleQuotedString(counter->name());
    1303           0 :   msg.WriteToLogFile();
    1304             : }
    1305             : 
    1306           0 : void Logger::TickEvent(v8::TickSample* sample, bool overflow) {
    1307           0 :   if (!log_->IsEnabled() || !FLAG_prof_cpp) return;
    1308           0 :   if (V8_UNLIKELY(FLAG_runtime_stats ==
    1309             :                   v8::tracing::TracingCategoryObserver::ENABLED_BY_NATIVE)) {
    1310           0 :     RuntimeCallTimerEvent();
    1311             :   }
    1312           0 :   Log::MessageBuilder msg(log_);
    1313           0 :   msg.Append("%s,", kLogEventsNames[CodeEventListener::TICK_EVENT]);
    1314           0 :   msg.AppendAddress(reinterpret_cast<Address>(sample->pc));
    1315           0 :   msg.Append(",%d", static_cast<int>(timer_.Elapsed().InMicroseconds()));
    1316           0 :   if (sample->has_external_callback) {
    1317           0 :     msg.Append(",1,");
    1318             :     msg.AppendAddress(
    1319           0 :         reinterpret_cast<Address>(sample->external_callback_entry));
    1320             :   } else {
    1321           0 :     msg.Append(",0,");
    1322           0 :     msg.AppendAddress(reinterpret_cast<Address>(sample->tos));
    1323             :   }
    1324           0 :   msg.Append(",%d", static_cast<int>(sample->state));
    1325           0 :   if (overflow) {
    1326           0 :     msg.Append(",overflow");
    1327             :   }
    1328           0 :   for (unsigned i = 0; i < sample->frames_count; ++i) {
    1329           0 :     msg.Append(',');
    1330           0 :     msg.AppendAddress(reinterpret_cast<Address>(sample->stack[i]));
    1331             :   }
    1332           0 :   msg.WriteToLogFile();
    1333             : }
    1334             : 
    1335           0 : void Logger::ICEvent(const char* type, bool keyed, const Address pc, int line,
    1336             :                      int column, Map* map, Object* key, char old_state,
    1337             :                      char new_state, const char* modifier,
    1338             :                      const char* slow_stub_reason) {
    1339           0 :   if (!log_->IsEnabled() || !FLAG_trace_ic) return;
    1340           0 :   Log::MessageBuilder msg(log_);
    1341           0 :   if (keyed) msg.Append("Keyed");
    1342           0 :   msg.Append("%s,", type);
    1343           0 :   msg.AppendAddress(pc);
    1344           0 :   msg.Append(",%d,%d,", line, column);
    1345           0 :   msg.Append(old_state);
    1346           0 :   msg.Append(",");
    1347           0 :   msg.Append(new_state);
    1348           0 :   msg.Append(",");
    1349           0 :   msg.AppendAddress(reinterpret_cast<Address>(map));
    1350           0 :   msg.Append(",");
    1351           0 :   if (key->IsSmi()) {
    1352           0 :     msg.Append("%d", Smi::cast(key)->value());
    1353           0 :   } else if (key->IsNumber()) {
    1354           0 :     msg.Append("%lf", key->Number());
    1355           0 :   } else if (key->IsString()) {
    1356           0 :     msg.AppendDetailed(String::cast(key), false);
    1357           0 :   } else if (key->IsSymbol()) {
    1358           0 :     msg.AppendSymbolName(Symbol::cast(key));
    1359             :   }
    1360           0 :   msg.Append(",%s,", modifier);
    1361           0 :   if (slow_stub_reason != nullptr) {
    1362           0 :     msg.AppendDoubleQuotedString(slow_stub_reason);
    1363             :   }
    1364           0 :   msg.WriteToLogFile();
    1365             : }
    1366             : 
    1367           0 : void Logger::CompareIC(const Address pc, int line, int column, Code* stub,
    1368             :                        const char* op, const char* old_left,
    1369             :                        const char* old_right, const char* old_state,
    1370             :                        const char* new_left, const char* new_right,
    1371             :                        const char* new_state) {
    1372           0 :   if (!log_->IsEnabled() || !FLAG_trace_ic) return;
    1373           0 :   Log::MessageBuilder msg(log_);
    1374           0 :   msg.Append("CompareIC,");
    1375           0 :   msg.AppendAddress(pc);
    1376           0 :   msg.Append(",%d,%d,", line, column);
    1377           0 :   msg.AppendAddress(reinterpret_cast<Address>(stub));
    1378             :   msg.Append(",%s,%s,%s,%s,%s,%s,%s", op, old_left, old_right, old_state,
    1379           0 :              new_left, new_right, new_state);
    1380           0 :   msg.WriteToLogFile();
    1381             : }
    1382             : 
    1383           0 : void Logger::BinaryOpIC(const Address pc, int line, int column, Code* stub,
    1384             :                         const char* old_state, const char* new_state,
    1385             :                         AllocationSite* allocation_site) {
    1386           0 :   if (!log_->IsEnabled() || !FLAG_trace_ic) return;
    1387           0 :   Log::MessageBuilder msg(log_);
    1388           0 :   msg.Append("BinaryOpIC,");
    1389           0 :   msg.AppendAddress(pc);
    1390           0 :   msg.Append(",%d,%d,", line, column);
    1391           0 :   msg.AppendAddress(reinterpret_cast<Address>(stub));
    1392           0 :   msg.Append(",%s,%s,", old_state, new_state);
    1393           0 :   if (allocation_site != nullptr) {
    1394           0 :     msg.AppendAddress(reinterpret_cast<Address>(allocation_site));
    1395             :   }
    1396           0 :   msg.WriteToLogFile();
    1397             : }
    1398             : 
    1399           0 : void Logger::ToBooleanIC(const Address pc, int line, int column, Code* stub,
    1400             :                          const char* old_state, const char* new_state) {
    1401           0 :   if (!log_->IsEnabled() || !FLAG_trace_ic) return;
    1402           0 :   Log::MessageBuilder msg(log_);
    1403           0 :   msg.Append("ToBooleanIC,");
    1404           0 :   msg.AppendAddress(pc);
    1405           0 :   msg.Append(",%d,%d,", line, column);
    1406           0 :   msg.AppendAddress(reinterpret_cast<Address>(stub));
    1407           0 :   msg.Append(",%s,%s,", old_state, new_state);
    1408           0 :   msg.WriteToLogFile();
    1409             : }
    1410             : 
    1411           0 : void Logger::PatchIC(const Address pc, const Address test, int delta) {
    1412           0 :   if (!log_->IsEnabled() || !FLAG_trace_ic) return;
    1413           0 :   Log::MessageBuilder msg(log_);
    1414           0 :   msg.Append("PatchIC,");
    1415           0 :   msg.AppendAddress(pc);
    1416           0 :   msg.Append(",");
    1417           0 :   msg.AppendAddress(test);
    1418           0 :   msg.Append(",");
    1419           0 :   msg.Append("%d,", delta);
    1420           0 :   msg.WriteToLogFile();
    1421             : }
    1422             : 
    1423           0 : void Logger::StopProfiler() {
    1424           0 :   if (!log_->IsEnabled()) return;
    1425           0 :   if (profiler_ != NULL) {
    1426             :     profiler_->pause();
    1427           0 :     is_logging_ = false;
    1428           0 :     removeCodeEventListener(this);
    1429             :   }
    1430             : }
    1431             : 
    1432             : 
    1433             : // This function can be called when Log's mutex is acquired,
    1434             : // either from main or Profiler's thread.
    1435           0 : void Logger::LogFailure() {
    1436           0 :   StopProfiler();
    1437           0 : }
    1438             : 
    1439      320994 : static void AddFunctionAndCode(SharedFunctionInfo* sfi,
    1440             :                                AbstractCode* code_object,
    1441             :                                Handle<SharedFunctionInfo>* sfis,
    1442             :                                Handle<AbstractCode>* code_objects, int offset) {
    1443      320994 :   if (sfis != NULL) {
    1444      320994 :     sfis[offset] = Handle<SharedFunctionInfo>(sfi);
    1445             :   }
    1446      320994 :   if (code_objects != NULL) {
    1447      320994 :     code_objects[offset] = Handle<AbstractCode>(code_object);
    1448             :   }
    1449      320994 : }
    1450             : 
    1451         684 : class EnumerateOptimizedFunctionsVisitor: public OptimizedFunctionVisitor {
    1452             :  public:
    1453             :   EnumerateOptimizedFunctionsVisitor(Handle<SharedFunctionInfo>* sfis,
    1454             :                                      Handle<AbstractCode>* code_objects,
    1455             :                                      int* count)
    1456         684 :       : sfis_(sfis), code_objects_(code_objects), count_(count) {}
    1457             : 
    1458         844 :   virtual void VisitFunction(JSFunction* function) {
    1459             :     SharedFunctionInfo* sfi = SharedFunctionInfo::cast(function->shared());
    1460             :     Object* maybe_script = sfi->script();
    1461         844 :     if (maybe_script->IsScript()
    1462        1688 :         && !Script::cast(maybe_script)->HasValidSource()) return;
    1463             : 
    1464             :     DCHECK(function->abstract_code()->kind() ==
    1465             :            AbstractCode::OPTIMIZED_FUNCTION);
    1466             :     AddFunctionAndCode(sfi, function->abstract_code(), sfis_, code_objects_,
    1467        1680 :                        *count_);
    1468         840 :     *count_ = *count_ + 1;
    1469             :   }
    1470             : 
    1471             :  private:
    1472             :   Handle<SharedFunctionInfo>* sfis_;
    1473             :   Handle<AbstractCode>* code_objects_;
    1474             :   int* count_;
    1475             : };
    1476             : 
    1477         684 : static int EnumerateCompiledFunctions(Heap* heap,
    1478             :                                       Handle<SharedFunctionInfo>* sfis,
    1479             :                                       Handle<AbstractCode>* code_objects) {
    1480         684 :   HeapIterator iterator(heap);
    1481             :   DisallowHeapAllocation no_gc;
    1482         684 :   int compiled_funcs_count = 0;
    1483             : 
    1484             :   // Iterate the heap to find shared function info objects and record
    1485             :   // the unoptimized code for them.
    1486     6556534 :   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
    1487     6555850 :     if (!obj->IsSharedFunctionInfo()) continue;
    1488             :     SharedFunctionInfo* sfi = SharedFunctionInfo::cast(obj);
    1489      572860 :     if (sfi->is_compiled()
    1490      893038 :         && (!sfi->script()->IsScript()
    1491        4208 :             || Script::cast(sfi->script())->HasValidSource())) {
    1492             :       // In some cases, an SFI might have (and have executing!) both bytecode
    1493             :       // and baseline code, so check for both and add them both if needed.
    1494      320154 :       if (sfi->HasBytecodeArray()) {
    1495             :         AddFunctionAndCode(sfi, AbstractCode::cast(sfi->bytecode_array()), sfis,
    1496        4872 :                            code_objects, compiled_funcs_count);
    1497        2436 :         ++compiled_funcs_count;
    1498             :       }
    1499             : 
    1500      320154 :       if (!sfi->IsInterpreted()) {
    1501             :         AddFunctionAndCode(sfi, AbstractCode::cast(sfi->code()), sfis,
    1502      635436 :                            code_objects, compiled_funcs_count);
    1503      317718 :         ++compiled_funcs_count;
    1504             :       }
    1505             :     }
    1506             :   }
    1507             : 
    1508             :   // Iterate all optimized functions in all contexts.
    1509             :   EnumerateOptimizedFunctionsVisitor visitor(sfis,
    1510             :                                              code_objects,
    1511             :                                              &compiled_funcs_count);
    1512         684 :   Deoptimizer::VisitAllOptimizedFunctions(heap->isolate(), &visitor);
    1513             : 
    1514        1368 :   return compiled_funcs_count;
    1515             : }
    1516             : 
    1517             : 
    1518       83387 : void Logger::LogCodeObject(Object* object) {
    1519             :   AbstractCode* code_object = AbstractCode::cast(object);
    1520             :   CodeEventListener::LogEventsAndTags tag = CodeEventListener::STUB_TAG;
    1521             :   const char* description = "Unknown code from the snapshot";
    1522       83387 :   switch (code_object->kind()) {
    1523             :     case AbstractCode::FUNCTION:
    1524             :     case AbstractCode::INTERPRETED_FUNCTION:
    1525             :     case AbstractCode::OPTIMIZED_FUNCTION:
    1526             :       return;  // We log this later using LogCompiledFunctions.
    1527             :     case AbstractCode::BYTECODE_HANDLER:
    1528             :       return;  // We log it later by walking the dispatch table.
    1529             :     case AbstractCode::BINARY_OP_IC:    // fall through
    1530             :     case AbstractCode::COMPARE_IC:      // fall through
    1531             :     case AbstractCode::TO_BOOLEAN_IC:   // fall through
    1532             : 
    1533             :     case AbstractCode::STUB:
    1534             :       description =
    1535       17157 :           CodeStub::MajorName(CodeStub::GetMajorKey(code_object->GetCode()));
    1536       17157 :       if (description == NULL)
    1537             :         description = "A stub from the snapshot";
    1538             :       tag = CodeEventListener::STUB_TAG;
    1539             :       break;
    1540             :     case AbstractCode::REGEXP:
    1541             :       description = "Regular expression code";
    1542             :       tag = CodeEventListener::REG_EXP_TAG;
    1543           0 :       break;
    1544             :     case AbstractCode::BUILTIN:
    1545             :       description =
    1546       37698 :           isolate_->builtins()->name(code_object->GetCode()->builtin_index());
    1547             :       tag = CodeEventListener::BUILTIN_TAG;
    1548       37698 :       break;
    1549             :     case AbstractCode::HANDLER:
    1550             :       description = "An IC handler from the snapshot";
    1551             :       tag = CodeEventListener::HANDLER_TAG;
    1552        1220 :       break;
    1553             :     case AbstractCode::KEYED_LOAD_IC:
    1554             :       description = "A keyed load IC from the snapshot";
    1555             :       tag = CodeEventListener::KEYED_LOAD_IC_TAG;
    1556         122 :       break;
    1557             :     case AbstractCode::LOAD_IC:
    1558             :       description = "A load IC from the snapshot";
    1559             :       tag = CodeEventListener::LOAD_IC_TAG;
    1560         122 :       break;
    1561             :     case AbstractCode::LOAD_GLOBAL_IC:
    1562             :       description = "A load global IC from the snapshot";
    1563             :       tag = Logger::LOAD_GLOBAL_IC_TAG;
    1564         244 :       break;
    1565             :     case AbstractCode::STORE_IC:
    1566             :       description = "A store IC from the snapshot";
    1567             :       tag = CodeEventListener::STORE_IC_TAG;
    1568         244 :       break;
    1569             :     case AbstractCode::STORE_GLOBAL_IC:
    1570             :       description = "A store global IC from the snapshot";
    1571             :       tag = CodeEventListener::STORE_GLOBAL_IC_TAG;
    1572           0 :       break;
    1573             :     case AbstractCode::KEYED_STORE_IC:
    1574             :       description = "A keyed store IC from the snapshot";
    1575             :       tag = CodeEventListener::KEYED_STORE_IC_TAG;
    1576         244 :       break;
    1577             :     case AbstractCode::WASM_FUNCTION:
    1578             :       description = "A Wasm function";
    1579             :       tag = CodeEventListener::STUB_TAG;
    1580           0 :       break;
    1581             :     case AbstractCode::JS_TO_WASM_FUNCTION:
    1582             :       description = "A JavaScript to Wasm adapter";
    1583             :       tag = CodeEventListener::STUB_TAG;
    1584           0 :       break;
    1585             :     case AbstractCode::WASM_TO_JS_FUNCTION:
    1586             :       description = "A Wasm to JavaScript adapter";
    1587             :       tag = CodeEventListener::STUB_TAG;
    1588           0 :       break;
    1589             :     case AbstractCode::WASM_INTERPRETER_ENTRY:
    1590             :       description = "A Wasm to Interpreter adapter";
    1591             :       tag = CodeEventListener::STUB_TAG;
    1592           0 :       break;
    1593             :     case AbstractCode::NUMBER_OF_KINDS:
    1594           0 :       UNIMPLEMENTED();
    1595             :   }
    1596      114102 :   PROFILE(isolate_, CodeCreateEvent(tag, code_object, description));
    1597             : }
    1598             : 
    1599             : 
    1600          61 : void Logger::LogCodeObjects() {
    1601          61 :   Heap* heap = isolate_->heap();
    1602          61 :   HeapIterator iterator(heap);
    1603             :   DisallowHeapAllocation no_gc;
    1604      519565 :   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
    1605      519504 :     if (obj->IsCode()) LogCodeObject(obj);
    1606      519504 :     if (obj->IsBytecodeArray()) LogCodeObject(obj);
    1607          61 :   }
    1608          61 : }
    1609             : 
    1610          24 : void Logger::LogBytecodeHandlers() {
    1611             :   const interpreter::OperandScale kOperandScales[] = {
    1612             : #define VALUE(Name, _) interpreter::OperandScale::k##Name,
    1613             :       OPERAND_SCALE_LIST(VALUE)
    1614             : #undef VALUE
    1615          24 :   };
    1616             : 
    1617             :   const int last_index = static_cast<int>(interpreter::Bytecode::kLast);
    1618          24 :   interpreter::Interpreter* interpreter = isolate_->interpreter();
    1619          96 :   for (auto operand_scale : kOperandScales) {
    1620       11952 :     for (int index = 0; index <= last_index; ++index) {
    1621       11880 :       interpreter::Bytecode bytecode = interpreter::Bytecodes::FromByte(index);
    1622       11880 :       if (interpreter::Bytecodes::BytecodeHasHandler(bytecode, operand_scale)) {
    1623       10488 :         Code* code = interpreter->GetBytecodeHandler(bytecode, operand_scale);
    1624             :         std::string bytecode_name =
    1625       10488 :             interpreter::Bytecodes::ToString(bytecode, operand_scale);
    1626       20976 :         PROFILE(isolate_, CodeCreateEvent(
    1627             :                               CodeEventListener::BYTECODE_HANDLER_TAG,
    1628             :                               AbstractCode::cast(code), bytecode_name.c_str()));
    1629             :       }
    1630             :     }
    1631             :   }
    1632          24 : }
    1633             : 
    1634      160497 : void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared,
    1635             :                                  Handle<AbstractCode> code) {
    1636      160497 :   if (shared->script()->IsScript()) {
    1637             :     Handle<Script> script(Script::cast(shared->script()));
    1638        2512 :     int line_num = Script::GetLineNumber(script, shared->start_position()) + 1;
    1639             :     int column_num =
    1640        2512 :         Script::GetColumnNumber(script, shared->start_position()) + 1;
    1641        2512 :     if (script->name()->IsString()) {
    1642             :       Handle<String> script_name(String::cast(script->name()));
    1643        1233 :       if (line_num > 0) {
    1644        2466 :         PROFILE(isolate_,
    1645             :                 CodeCreateEvent(
    1646             :                     Logger::ToNativeByScript(
    1647             :                         CodeEventListener::LAZY_COMPILE_TAG, *script),
    1648             :                     *code, *shared, *script_name, line_num, column_num));
    1649             :       } else {
    1650             :         // Can't distinguish eval and script here, so always use Script.
    1651           0 :         PROFILE(isolate_,
    1652             :                 CodeCreateEvent(Logger::ToNativeByScript(
    1653             :                                     CodeEventListener::SCRIPT_TAG, *script),
    1654             :                                 *code, *shared, *script_name));
    1655             :       }
    1656             :     } else {
    1657        2558 :       PROFILE(isolate_,
    1658             :               CodeCreateEvent(Logger::ToNativeByScript(
    1659             :                                   CodeEventListener::LAZY_COMPILE_TAG, *script),
    1660             :                               *code, *shared, isolate_->heap()->empty_string(),
    1661             :                               line_num, column_num));
    1662             :     }
    1663      157985 :   } else if (shared->IsApiFunction()) {
    1664             :     // API function.
    1665             :     FunctionTemplateInfo* fun_data = shared->get_api_func_data();
    1666             :     Object* raw_call_data = fun_data->call_code();
    1667       14868 :     if (!raw_call_data->IsUndefined(isolate_)) {
    1668             :       CallHandlerInfo* call_data = CallHandlerInfo::cast(raw_call_data);
    1669             :       Object* callback_obj = call_data->callback();
    1670             :       Address entry_point = v8::ToCData<Address>(callback_obj);
    1671             : #if USES_FUNCTION_DESCRIPTORS
    1672             :       entry_point = *FUNCTION_ENTRYPOINT_ADDRESS(entry_point);
    1673             : #endif
    1674       14680 :       PROFILE(isolate_, CallbackEvent(shared->DebugName(), entry_point));
    1675             :     }
    1676             :   } else {
    1677      301102 :     PROFILE(isolate_,
    1678             :             CodeCreateEvent(CodeEventListener::LAZY_COMPILE_TAG, *code, *shared,
    1679             :                             isolate_->heap()->empty_string()));
    1680             :   }
    1681      160497 : }
    1682             : 
    1683             : 
    1684         342 : void Logger::LogCompiledFunctions() {
    1685         342 :   Heap* heap = isolate_->heap();
    1686             :   HandleScope scope(isolate_);
    1687         342 :   const int compiled_funcs_count = EnumerateCompiledFunctions(heap, NULL, NULL);
    1688             :   ScopedVector< Handle<SharedFunctionInfo> > sfis(compiled_funcs_count);
    1689             :   ScopedVector<Handle<AbstractCode> > code_objects(compiled_funcs_count);
    1690         342 :   EnumerateCompiledFunctions(heap, sfis.start(), code_objects.start());
    1691             : 
    1692             :   // During iteration, there can be heap allocation due to
    1693             :   // GetScriptLineNumber call.
    1694      160839 :   for (int i = 0; i < compiled_funcs_count; ++i) {
    1695      320994 :     if (code_objects[i].is_identical_to(isolate_->builtins()->CompileLazy()))
    1696             :       continue;
    1697      160497 :     LogExistingFunction(sfis[i], code_objects[i]);
    1698             :   }
    1699         342 : }
    1700             : 
    1701             : 
    1702         300 : void Logger::LogAccessorCallbacks() {
    1703         300 :   Heap* heap = isolate_->heap();
    1704         300 :   HeapIterator iterator(heap);
    1705             :   DisallowHeapAllocation no_gc;
    1706     2954949 :   for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
    1707     2954649 :     if (!obj->IsAccessorInfo()) continue;
    1708             :     AccessorInfo* ai = AccessorInfo::cast(obj);
    1709       17796 :     if (!ai->name()->IsName()) continue;
    1710             :     Address getter_entry = v8::ToCData<Address>(ai->getter());
    1711             :     Name* name = Name::cast(ai->name());
    1712       17796 :     if (getter_entry != 0) {
    1713             : #if USES_FUNCTION_DESCRIPTORS
    1714             :       getter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(getter_entry);
    1715             : #endif
    1716       35592 :       PROFILE(isolate_, GetterCallbackEvent(name, getter_entry));
    1717             :     }
    1718             :     Address setter_entry = v8::ToCData<Address>(ai->setter());
    1719       17796 :     if (setter_entry != 0) {
    1720             : #if USES_FUNCTION_DESCRIPTORS
    1721             :       setter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(setter_entry);
    1722             : #endif
    1723       35580 :       PROFILE(isolate_, SetterCallbackEvent(name, setter_entry));
    1724             :     }
    1725         300 :   }
    1726         300 : }
    1727             : 
    1728             : 
    1729       60782 : static void AddIsolateIdIfNeeded(std::ostream& os,  // NOLINT
    1730             :                                  Isolate* isolate) {
    1731       92083 :   if (FLAG_logfile_per_isolate) os << "isolate-" << isolate << "-";
    1732       60782 : }
    1733             : 
    1734             : 
    1735       60782 : static void PrepareLogFileName(std::ostream& os,  // NOLINT
    1736             :                                Isolate* isolate, const char* file_name) {
    1737             :   int dir_separator_count = 0;
    1738      425354 :   for (const char* p = file_name; *p; p++) {
    1739      364572 :     if (base::OS::isDirectorySeparator(*p)) dir_separator_count++;
    1740             :   }
    1741             : 
    1742      364572 :   for (const char* p = file_name; *p; p++) {
    1743      364572 :     if (dir_separator_count == 0) {
    1744       60782 :       AddIsolateIdIfNeeded(os, isolate);
    1745       60782 :       dir_separator_count--;
    1746             :     }
    1747      364572 :     if (*p == '%') {
    1748           0 :       p++;
    1749           0 :       switch (*p) {
    1750             :         case '\0':
    1751             :           // If there's a % at the end of the string we back up
    1752             :           // one character so we can escape the loop properly.
    1753             :           p--;
    1754             :           break;
    1755             :         case 'p':
    1756           0 :           os << base::OS::GetCurrentProcessId();
    1757           0 :           break;
    1758             :         case 't':
    1759             :           // %t expands to the current time in milliseconds.
    1760           0 :           os << static_cast<int64_t>(base::OS::TimeCurrentMillis());
    1761             :           break;
    1762             :         case '%':
    1763             :           // %% expands (contracts really) to %.
    1764             :           os << '%';
    1765             :           break;
    1766             :         default:
    1767             :           // All other %'s expand to themselves.
    1768             :           os << '%' << *p;
    1769             :           break;
    1770             :       }
    1771             :     } else {
    1772      364572 :       if (base::OS::isDirectorySeparator(*p)) dir_separator_count--;
    1773      364572 :       os << *p;
    1774             :     }
    1775             :   }
    1776       60782 : }
    1777             : 
    1778             : 
    1779       60782 : bool Logger::SetUp(Isolate* isolate) {
    1780             :   // Tests and EnsureInitialize() can call this twice in a row. It's harmless.
    1781       60782 :   if (is_initialized_) return true;
    1782       60782 :   is_initialized_ = true;
    1783             : 
    1784       60782 :   std::ostringstream log_file_name;
    1785       60782 :   PrepareLogFileName(log_file_name, isolate, FLAG_logfile);
    1786      121564 :   log_->Initialize(log_file_name.str().c_str());
    1787             : 
    1788       60782 :   if (FLAG_perf_basic_prof) {
    1789           0 :     perf_basic_logger_ = new PerfBasicLogger();
    1790             :     addCodeEventListener(perf_basic_logger_);
    1791             :   }
    1792             : 
    1793       60782 :   if (FLAG_perf_prof) {
    1794           0 :     perf_jit_logger_ = new PerfJitLogger();
    1795             :     addCodeEventListener(perf_jit_logger_);
    1796             :   }
    1797             : 
    1798       60782 :   if (FLAG_ll_prof) {
    1799           0 :     ll_logger_ = new LowLevelLogger(log_file_name.str().c_str());
    1800           0 :     addCodeEventListener(ll_logger_);
    1801             :   }
    1802             : 
    1803       60782 :   ticker_ = new Ticker(isolate, FLAG_prof_sampling_interval);
    1804             : 
    1805       60782 :   if (Log::InitLogAtStart()) {
    1806          24 :     is_logging_ = true;
    1807             :   }
    1808             : 
    1809       60782 :   if (FLAG_log_internal_timer_events || FLAG_prof_cpp) timer_.Start();
    1810             : 
    1811       60782 :   if (FLAG_prof_cpp) {
    1812           0 :     profiler_ = new Profiler(isolate);
    1813           0 :     is_logging_ = true;
    1814           0 :     profiler_->Engage();
    1815             :   }
    1816             : 
    1817             :   profiler_listener_.reset();
    1818             : 
    1819       60782 :   if (is_logging_) {
    1820          24 :     addCodeEventListener(this);
    1821             :   }
    1822             : 
    1823       60782 :   return true;
    1824             : }
    1825             : 
    1826             : 
    1827          72 : void Logger::SetCodeEventHandler(uint32_t options,
    1828             :                                  JitCodeEventHandler event_handler) {
    1829          72 :   if (jit_logger_) {
    1830             :       removeCodeEventListener(jit_logger_);
    1831          33 :       delete jit_logger_;
    1832          33 :       jit_logger_ = NULL;
    1833             :   }
    1834             : 
    1835          72 :   if (event_handler) {
    1836          39 :     jit_logger_ = new JitLogger(event_handler);
    1837             :     addCodeEventListener(jit_logger_);
    1838          39 :     if (options & kJitCodeEventEnumExisting) {
    1839           6 :       HandleScope scope(isolate_);
    1840           6 :       LogCodeObjects();
    1841           6 :       LogCompiledFunctions();
    1842             :     }
    1843             :   }
    1844          72 : }
    1845             : 
    1846         294 : void Logger::SetUpProfilerListener() {
    1847         588 :   if (!is_initialized_) return;
    1848         294 :   if (profiler_listener_.get() == nullptr) {
    1849         258 :     profiler_listener_.reset(new ProfilerListener(isolate_));
    1850             :   }
    1851             :   addCodeEventListener(profiler_listener_.get());
    1852             : }
    1853             : 
    1854         294 : void Logger::TearDownProfilerListener() {
    1855         588 :   if (profiler_listener_->HasObservers()) return;
    1856             :   removeCodeEventListener(profiler_listener_.get());
    1857             : }
    1858             : 
    1859       59283 : sampler::Sampler* Logger::sampler() {
    1860       59283 :   return ticker_;
    1861             : }
    1862             : 
    1863             : 
    1864       59327 : FILE* Logger::TearDown() {
    1865       59327 :   if (!is_initialized_) return NULL;
    1866       59285 :   is_initialized_ = false;
    1867             : 
    1868             :   // Stop the profiler before closing the file.
    1869       59285 :   if (profiler_ != NULL) {
    1870           0 :     profiler_->Disengage();
    1871           0 :     delete profiler_;
    1872           0 :     profiler_ = NULL;
    1873             :   }
    1874             : 
    1875       59285 :   delete ticker_;
    1876       59285 :   ticker_ = NULL;
    1877             : 
    1878       59285 :   if (perf_basic_logger_) {
    1879             :     removeCodeEventListener(perf_basic_logger_);
    1880           0 :     delete perf_basic_logger_;
    1881           0 :     perf_basic_logger_ = NULL;
    1882             :   }
    1883             : 
    1884       59285 :   if (perf_jit_logger_) {
    1885             :     removeCodeEventListener(perf_jit_logger_);
    1886           0 :     delete perf_jit_logger_;
    1887           0 :     perf_jit_logger_ = NULL;
    1888             :   }
    1889             : 
    1890       59285 :   if (ll_logger_) {
    1891             :     removeCodeEventListener(ll_logger_);
    1892           0 :     delete ll_logger_;
    1893           0 :     ll_logger_ = NULL;
    1894             :   }
    1895             : 
    1896       59285 :   if (jit_logger_) {
    1897             :     removeCodeEventListener(jit_logger_);
    1898           6 :     delete jit_logger_;
    1899           6 :     jit_logger_ = NULL;
    1900             :   }
    1901             : 
    1902       59285 :   if (profiler_listener_.get() != nullptr) {
    1903             :     removeCodeEventListener(profiler_listener_.get());
    1904             :   }
    1905             : 
    1906       59285 :   return log_->Close();
    1907             : }
    1908             : 
    1909             : }  // namespace internal
    1910             : }  // namespace v8

Generated by: LCOV version 1.10