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