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