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