• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 // Copyright 2011 the V8 project authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4 
5 #include "src/log.h"
6 
7 #include <cstdarg>
8 #include <memory>
9 #include <sstream>
10 
11 #include "src/api-inl.h"
12 #include "src/bailout-reason.h"
13 #include "src/base/platform/platform.h"
14 #include "src/bootstrapper.h"
15 #include "src/code-stubs.h"
16 #include "src/counters.h"
17 #include "src/deoptimizer.h"
18 #include "src/global-handles.h"
19 #include "src/instruction-stream.h"
20 #include "src/interpreter/bytecodes.h"
21 #include "src/interpreter/interpreter.h"
22 #include "src/libsampler/sampler.h"
23 #include "src/log-inl.h"
24 #include "src/macro-assembler.h"
25 #include "src/objects/api-callbacks.h"
26 #include "src/perf-jit.h"
27 #include "src/profiler/tick-sample.h"
28 #include "src/runtime-profiler.h"
29 #include "src/source-position-table.h"
30 #include "src/string-stream.h"
31 #include "src/tracing/tracing-category-observer.h"
32 #include "src/unicode-inl.h"
33 #include "src/vm-state-inl.h"
34 #include "src/wasm/wasm-code-manager.h"
35 #include "src/wasm/wasm-objects-inl.h"
36 
37 #include "src/utils.h"
38 #include "src/version.h"
39 
40 namespace v8 {
41 namespace internal {
42 
43 #define DECLARE_EVENT(ignore1, name) #name,
44 static const char* kLogEventsNames[CodeEventListener::NUMBER_OF_LOG_EVENTS] = {
45     LOG_EVENTS_AND_TAGS_LIST(DECLARE_EVENT)};
46 #undef DECLARE_EVENT
47 
GetCodeEventTypeForTag(CodeEventListener::LogEventsAndTags tag)48 static v8::CodeEventType GetCodeEventTypeForTag(
49     CodeEventListener::LogEventsAndTags tag) {
50   switch (tag) {
51     case CodeEventListener::NUMBER_OF_LOG_EVENTS:
52 #define V(Event, _) case CodeEventListener::Event:
53       LOG_EVENTS_LIST(V)
54 #undef V
55       return v8::CodeEventType::kUnknownType;
56 #define V(From, To)             \
57   case CodeEventListener::From: \
58     return v8::CodeEventType::k##To##Type;
59       TAGS_LIST(V)
60 #undef V
61   }
62   // The execution should never pass here
63   UNREACHABLE();
64   // NOTE(mmarchini): Workaround to fix a compiler failure on GCC 4.9
65   return v8::CodeEventType::kUnknownType;
66 }
67 #define CALL_CODE_EVENT_HANDLER(Call) \
68   if (listener_) {                    \
69     listener_->Call;                  \
70   } else {                            \
71     PROFILE(isolate_, Call);          \
72   }
73 
ComputeMarker(SharedFunctionInfo * shared,AbstractCode * code)74 static const char* ComputeMarker(SharedFunctionInfo* shared,
75                                  AbstractCode* code) {
76   switch (code->kind()) {
77     case AbstractCode::INTERPRETED_FUNCTION:
78       return shared->optimization_disabled() ? "" : "~";
79     case AbstractCode::OPTIMIZED_FUNCTION:
80       return "*";
81     default:
82       return "";
83   }
84 }
85 
ComputeMarker(const wasm::WasmCode * code)86 static const char* ComputeMarker(const wasm::WasmCode* code) {
87   switch (code->kind()) {
88     case wasm::WasmCode::kFunction:
89       return code->is_liftoff() ? "" : "*";
90     case wasm::WasmCode::kInterpreterEntry:
91       return "~";
92     default:
93       return "";
94   }
95 }
96 
97 class CodeEventLogger::NameBuffer {
98  public:
NameBuffer()99   NameBuffer() { Reset(); }
100 
Reset()101   void Reset() {
102     utf8_pos_ = 0;
103   }
104 
Init(CodeEventListener::LogEventsAndTags tag)105   void Init(CodeEventListener::LogEventsAndTags tag) {
106     Reset();
107     AppendBytes(kLogEventsNames[tag]);
108     AppendByte(':');
109   }
110 
AppendName(Name * name)111   void AppendName(Name* name) {
112     if (name->IsString()) {
113       AppendString(String::cast(name));
114     } else {
115       Symbol* symbol = Symbol::cast(name);
116       AppendBytes("symbol(");
117       if (!symbol->name()->IsUndefined()) {
118         AppendBytes("\"");
119         AppendString(String::cast(symbol->name()));
120         AppendBytes("\" ");
121       }
122       AppendBytes("hash ");
123       AppendHex(symbol->Hash());
124       AppendByte(')');
125     }
126   }
127 
AppendString(String * str)128   void AppendString(String* str) {
129     if (str == nullptr) return;
130     int length = 0;
131     std::unique_ptr<char[]> c_str =
132         str->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL, &length);
133     AppendBytes(c_str.get(), length);
134   }
135 
AppendBytes(const char * bytes,int size)136   void AppendBytes(const char* bytes, int size) {
137     size = Min(size, kUtf8BufferSize - utf8_pos_);
138     MemCopy(utf8_buffer_ + utf8_pos_, bytes, size);
139     utf8_pos_ += size;
140   }
141 
AppendBytes(const char * bytes)142   void AppendBytes(const char* bytes) {
143     AppendBytes(bytes, StrLength(bytes));
144   }
145 
AppendByte(char c)146   void AppendByte(char c) {
147     if (utf8_pos_ >= kUtf8BufferSize) return;
148     utf8_buffer_[utf8_pos_++] = c;
149   }
150 
AppendInt(int n)151   void AppendInt(int n) {
152     int space = kUtf8BufferSize - utf8_pos_;
153     if (space <= 0) return;
154     Vector<char> buffer(utf8_buffer_ + utf8_pos_, space);
155     int size = SNPrintF(buffer, "%d", n);
156     if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {
157       utf8_pos_ += size;
158     }
159   }
160 
AppendHex(uint32_t n)161   void AppendHex(uint32_t n) {
162     int space = kUtf8BufferSize - utf8_pos_;
163     if (space <= 0) return;
164     Vector<char> buffer(utf8_buffer_ + utf8_pos_, space);
165     int size = SNPrintF(buffer, "%x", n);
166     if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {
167       utf8_pos_ += size;
168     }
169   }
170 
get()171   const char* get() { return utf8_buffer_; }
size() const172   int size() const { return utf8_pos_; }
173 
174  private:
175   static const int kUtf8BufferSize = 512;
176   static const int kUtf16BufferSize = kUtf8BufferSize;
177 
178   int utf8_pos_;
179   char utf8_buffer_[kUtf8BufferSize];
180 };
181 
CodeEventLogger(Isolate * isolate)182 CodeEventLogger::CodeEventLogger(Isolate* isolate)
183     : isolate_(isolate), name_buffer_(new NameBuffer) {}
184 
~CodeEventLogger()185 CodeEventLogger::~CodeEventLogger() { delete name_buffer_; }
186 
CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,AbstractCode * code,const char * comment)187 void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
188                                       AbstractCode* code, const char* comment) {
189   name_buffer_->Init(tag);
190   name_buffer_->AppendBytes(comment);
191   LogRecordedBuffer(code, nullptr, name_buffer_->get(), name_buffer_->size());
192 }
193 
CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,AbstractCode * code,Name * name)194 void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
195                                       AbstractCode* code, Name* name) {
196   name_buffer_->Init(tag);
197   name_buffer_->AppendName(name);
198   LogRecordedBuffer(code, nullptr, name_buffer_->get(), name_buffer_->size());
199 }
200 
CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,AbstractCode * code,SharedFunctionInfo * shared,Name * name)201 void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
202                                       AbstractCode* code,
203                                       SharedFunctionInfo* shared, Name* name) {
204   name_buffer_->Init(tag);
205   name_buffer_->AppendBytes(ComputeMarker(shared, code));
206   name_buffer_->AppendName(name);
207   LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());
208 }
209 
CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,AbstractCode * code,SharedFunctionInfo * shared,Name * source,int line,int column)210 void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
211                                       AbstractCode* code,
212                                       SharedFunctionInfo* shared, Name* source,
213                                       int line, int column) {
214   name_buffer_->Init(tag);
215   name_buffer_->AppendBytes(ComputeMarker(shared, code));
216   name_buffer_->AppendString(shared->DebugName());
217   name_buffer_->AppendByte(' ');
218   if (source->IsString()) {
219     name_buffer_->AppendString(String::cast(source));
220   } else {
221     name_buffer_->AppendBytes("symbol(hash ");
222     name_buffer_->AppendHex(Name::cast(source)->Hash());
223     name_buffer_->AppendByte(')');
224   }
225   name_buffer_->AppendByte(':');
226   name_buffer_->AppendInt(line);
227   LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());
228 }
229 
CodeCreateEvent(LogEventsAndTags tag,const wasm::WasmCode * code,wasm::WasmName name)230 void CodeEventLogger::CodeCreateEvent(LogEventsAndTags tag,
231                                       const wasm::WasmCode* code,
232                                       wasm::WasmName name) {
233   name_buffer_->Init(tag);
234   if (name.is_empty()) {
235     name_buffer_->AppendBytes("<wasm-unknown>");
236   } else {
237     name_buffer_->AppendBytes(name.start(), name.length());
238   }
239   name_buffer_->AppendByte('-');
240   if (code->IsAnonymous()) {
241     name_buffer_->AppendBytes("<anonymous>");
242   } else {
243     name_buffer_->AppendInt(code->index());
244   }
245   LogRecordedBuffer(code, name_buffer_->get(), name_buffer_->size());
246 }
247 
RegExpCodeCreateEvent(AbstractCode * code,String * source)248 void CodeEventLogger::RegExpCodeCreateEvent(AbstractCode* code,
249                                             String* source) {
250   name_buffer_->Init(CodeEventListener::REG_EXP_TAG);
251   name_buffer_->AppendString(source);
252   LogRecordedBuffer(code, nullptr, name_buffer_->get(), name_buffer_->size());
253 }
254 
255 // Linux perf tool logging support
256 class PerfBasicLogger : public CodeEventLogger {
257  public:
258   explicit PerfBasicLogger(Isolate* isolate);
259   ~PerfBasicLogger() override;
260 
CodeMoveEvent(AbstractCode * from,AbstractCode * to)261   void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override {}
CodeDisableOptEvent(AbstractCode * code,SharedFunctionInfo * shared)262   void CodeDisableOptEvent(AbstractCode* code,
263                            SharedFunctionInfo* shared) override {}
264 
265  private:
266   void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
267                          const char* name, int length) override;
268   void LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
269                          int length) override;
270   void WriteLogRecordedBuffer(uintptr_t address, int size, const char* name,
271                               int name_length);
272 
273   // Extension added to V8 log file name to get the low-level log name.
274   static const char kFilenameFormatString[];
275   static const int kFilenameBufferPadding;
276 
277   FILE* perf_output_handle_;
278 };
279 
280 const char PerfBasicLogger::kFilenameFormatString[] = "/tmp/perf-%d.map";
281 // Extra space for the PID in the filename
282 const int PerfBasicLogger::kFilenameBufferPadding = 16;
283 
PerfBasicLogger(Isolate * isolate)284 PerfBasicLogger::PerfBasicLogger(Isolate* isolate)
285     : CodeEventLogger(isolate), perf_output_handle_(nullptr) {
286   // Open the perf JIT dump file.
287   int bufferSize = sizeof(kFilenameFormatString) + kFilenameBufferPadding;
288   ScopedVector<char> perf_dump_name(bufferSize);
289   int size = SNPrintF(
290       perf_dump_name,
291       kFilenameFormatString,
292       base::OS::GetCurrentProcessId());
293   CHECK_NE(size, -1);
294   perf_output_handle_ =
295       base::OS::FOpen(perf_dump_name.start(), base::OS::LogFileOpenMode);
296   CHECK_NOT_NULL(perf_output_handle_);
297   setvbuf(perf_output_handle_, nullptr, _IOLBF, 0);
298 }
299 
300 
~PerfBasicLogger()301 PerfBasicLogger::~PerfBasicLogger() {
302   fclose(perf_output_handle_);
303   perf_output_handle_ = nullptr;
304 }
305 
WriteLogRecordedBuffer(uintptr_t address,int size,const char * name,int name_length)306 void PerfBasicLogger::WriteLogRecordedBuffer(uintptr_t address, int size,
307                                              const char* name,
308                                              int name_length) {
309   // Linux perf expects hex literals without a leading 0x, while some
310   // implementations of printf might prepend one when using the %p format
311   // for pointers, leading to wrongly formatted JIT symbols maps.
312   //
313   // Instead, we use V8PRIxPTR format string and cast pointer to uintpr_t,
314   // so that we have control over the exact output format.
315   base::OS::FPrint(perf_output_handle_, "%" V8PRIxPTR " %x %.*s\n", address,
316                    size, name_length, name);
317 }
318 
LogRecordedBuffer(AbstractCode * code,SharedFunctionInfo *,const char * name,int length)319 void PerfBasicLogger::LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo*,
320                                         const char* name, int length) {
321   if (FLAG_perf_basic_prof_only_functions &&
322       (code->kind() != AbstractCode::INTERPRETED_FUNCTION &&
323        code->kind() != AbstractCode::BUILTIN &&
324        code->kind() != AbstractCode::OPTIMIZED_FUNCTION)) {
325     return;
326   }
327 
328   WriteLogRecordedBuffer(static_cast<uintptr_t>(code->InstructionStart()),
329                          code->InstructionSize(), name, length);
330 }
331 
LogRecordedBuffer(const wasm::WasmCode * code,const char * name,int length)332 void PerfBasicLogger::LogRecordedBuffer(const wasm::WasmCode* code,
333                                         const char* name, int length) {
334   WriteLogRecordedBuffer(static_cast<uintptr_t>(code->instruction_start()),
335                          code->instructions().length(), name, length);
336 }
337 
338 // External CodeEventListener
ExternalCodeEventListener(Isolate * isolate)339 ExternalCodeEventListener::ExternalCodeEventListener(Isolate* isolate)
340     : is_listening_(false), isolate_(isolate), code_event_handler_(nullptr) {}
341 
~ExternalCodeEventListener()342 ExternalCodeEventListener::~ExternalCodeEventListener() {
343   if (is_listening_) {
344     StopListening();
345   }
346 }
347 
LogExistingCode()348 void ExternalCodeEventListener::LogExistingCode() {
349   HandleScope scope(isolate_);
350   ExistingCodeLogger logger(isolate_, this);
351   logger.LogCodeObjects();
352   logger.LogBytecodeHandlers();
353   logger.LogCompiledFunctions();
354 }
355 
StartListening(CodeEventHandler * code_event_handler)356 void ExternalCodeEventListener::StartListening(
357     CodeEventHandler* code_event_handler) {
358   if (is_listening_ || code_event_handler == nullptr) {
359     return;
360   }
361   code_event_handler_ = code_event_handler;
362   is_listening_ = isolate_->code_event_dispatcher()->AddListener(this);
363   if (is_listening_) {
364     LogExistingCode();
365   }
366 }
367 
StopListening()368 void ExternalCodeEventListener::StopListening() {
369   if (!is_listening_) {
370     return;
371   }
372 
373   isolate_->code_event_dispatcher()->RemoveListener(this);
374   is_listening_ = false;
375 }
376 
CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,AbstractCode * code,const char * comment)377 void ExternalCodeEventListener::CodeCreateEvent(
378     CodeEventListener::LogEventsAndTags tag, AbstractCode* code,
379     const char* comment) {
380   CodeEvent code_event;
381   code_event.code_start_address =
382       static_cast<uintptr_t>(code->InstructionStart());
383   code_event.code_size = static_cast<size_t>(code->InstructionSize());
384   code_event.function_name = isolate_->factory()->empty_string();
385   code_event.script_name = isolate_->factory()->empty_string();
386   code_event.script_line = 0;
387   code_event.script_column = 0;
388   code_event.code_type = GetCodeEventTypeForTag(tag);
389   code_event.comment = comment;
390 
391   code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
392 }
393 
CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,AbstractCode * code,Name * name)394 void ExternalCodeEventListener::CodeCreateEvent(
395     CodeEventListener::LogEventsAndTags tag, AbstractCode* code, Name* name) {
396   Handle<String> name_string =
397       Name::ToFunctionName(isolate_, Handle<Name>(name, isolate_))
398           .ToHandleChecked();
399 
400   CodeEvent code_event;
401   code_event.code_start_address =
402       static_cast<uintptr_t>(code->InstructionStart());
403   code_event.code_size = static_cast<size_t>(code->InstructionSize());
404   code_event.function_name = name_string;
405   code_event.script_name = isolate_->factory()->empty_string();
406   code_event.script_line = 0;
407   code_event.script_column = 0;
408   code_event.code_type = GetCodeEventTypeForTag(tag);
409   code_event.comment = "";
410 
411   code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
412 }
413 
CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,AbstractCode * code,SharedFunctionInfo * shared,Name * name)414 void ExternalCodeEventListener::CodeCreateEvent(
415     CodeEventListener::LogEventsAndTags tag, AbstractCode* code,
416     SharedFunctionInfo* shared, Name* name) {
417   Handle<String> name_string =
418       Name::ToFunctionName(isolate_, Handle<Name>(name, isolate_))
419           .ToHandleChecked();
420 
421   CodeEvent code_event;
422   code_event.code_start_address =
423       static_cast<uintptr_t>(code->InstructionStart());
424   code_event.code_size = static_cast<size_t>(code->InstructionSize());
425   code_event.function_name = name_string;
426   code_event.script_name = isolate_->factory()->empty_string();
427   code_event.script_line = 0;
428   code_event.script_column = 0;
429   code_event.code_type = GetCodeEventTypeForTag(tag);
430   code_event.comment = "";
431 
432   code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
433 }
434 
CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,AbstractCode * code,SharedFunctionInfo * shared,Name * source,int line,int column)435 void ExternalCodeEventListener::CodeCreateEvent(
436     CodeEventListener::LogEventsAndTags tag, AbstractCode* code,
437     SharedFunctionInfo* shared, Name* source, int line, int column) {
438   Handle<String> name_string =
439       Name::ToFunctionName(isolate_, Handle<Name>(shared->Name(), isolate_))
440           .ToHandleChecked();
441   Handle<String> source_string =
442       Name::ToFunctionName(isolate_, Handle<Name>(source, isolate_))
443           .ToHandleChecked();
444 
445   CodeEvent code_event;
446   code_event.code_start_address =
447       static_cast<uintptr_t>(code->InstructionStart());
448   code_event.code_size = static_cast<size_t>(code->InstructionSize());
449   code_event.function_name = name_string;
450   code_event.script_name = source_string;
451   code_event.script_line = line;
452   code_event.script_column = column;
453   code_event.code_type = GetCodeEventTypeForTag(tag);
454   code_event.comment = "";
455 
456   code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
457 }
458 
CodeCreateEvent(LogEventsAndTags tag,const wasm::WasmCode * code,wasm::WasmName name)459 void ExternalCodeEventListener::CodeCreateEvent(LogEventsAndTags tag,
460                                                 const wasm::WasmCode* code,
461                                                 wasm::WasmName name) {
462   // TODO(mmarchini): handle later
463 }
464 
RegExpCodeCreateEvent(AbstractCode * code,String * source)465 void ExternalCodeEventListener::RegExpCodeCreateEvent(AbstractCode* code,
466                                                       String* source) {
467   CodeEvent code_event;
468   code_event.code_start_address =
469       static_cast<uintptr_t>(code->InstructionStart());
470   code_event.code_size = static_cast<size_t>(code->InstructionSize());
471   code_event.function_name = Handle<String>(source, isolate_);
472   code_event.script_name = isolate_->factory()->empty_string();
473   code_event.script_line = 0;
474   code_event.script_column = 0;
475   code_event.code_type = GetCodeEventTypeForTag(CodeEventListener::REG_EXP_TAG);
476   code_event.comment = "";
477 
478   code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
479 }
480 
481 // Low-level logging support.
482 class LowLevelLogger : public CodeEventLogger {
483  public:
484   LowLevelLogger(Isolate* isolate, const char* file_name);
485   ~LowLevelLogger() override;
486 
487   void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override;
CodeDisableOptEvent(AbstractCode * code,SharedFunctionInfo * shared)488   void CodeDisableOptEvent(AbstractCode* code,
489                            SharedFunctionInfo* shared) override {}
490   void SnapshotPositionEvent(HeapObject* obj, int pos);
491   void CodeMovingGCEvent() override;
492 
493  private:
494   void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
495                          const char* name, int length) override;
496   void LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
497                          int length) override;
498 
499   // Low-level profiling event structures.
500   struct CodeCreateStruct {
501     static const char kTag = 'C';
502 
503     int32_t name_size;
504     Address code_address;
505     int32_t code_size;
506   };
507 
508 
509   struct CodeMoveStruct {
510     static const char kTag = 'M';
511 
512     Address from_address;
513     Address to_address;
514   };
515 
516 
517   static const char kCodeMovingGCTag = 'G';
518 
519 
520   // Extension added to V8 log file name to get the low-level log name.
521   static const char kLogExt[];
522 
523   void LogCodeInfo();
524   void LogWriteBytes(const char* bytes, int size);
525 
526   template <typename T>
LogWriteStruct(const T & s)527   void LogWriteStruct(const T& s) {
528     char tag = T::kTag;
529     LogWriteBytes(reinterpret_cast<const char*>(&tag), sizeof(tag));
530     LogWriteBytes(reinterpret_cast<const char*>(&s), sizeof(s));
531   }
532 
533   FILE* ll_output_handle_;
534 };
535 
536 const char LowLevelLogger::kLogExt[] = ".ll";
537 
LowLevelLogger(Isolate * isolate,const char * name)538 LowLevelLogger::LowLevelLogger(Isolate* isolate, const char* name)
539     : CodeEventLogger(isolate), ll_output_handle_(nullptr) {
540   // Open the low-level log file.
541   size_t len = strlen(name);
542   ScopedVector<char> ll_name(static_cast<int>(len + sizeof(kLogExt)));
543   MemCopy(ll_name.start(), name, len);
544   MemCopy(ll_name.start() + len, kLogExt, sizeof(kLogExt));
545   ll_output_handle_ =
546       base::OS::FOpen(ll_name.start(), base::OS::LogFileOpenMode);
547   setvbuf(ll_output_handle_, nullptr, _IOLBF, 0);
548 
549   LogCodeInfo();
550 }
551 
552 
~LowLevelLogger()553 LowLevelLogger::~LowLevelLogger() {
554   fclose(ll_output_handle_);
555   ll_output_handle_ = nullptr;
556 }
557 
558 
LogCodeInfo()559 void LowLevelLogger::LogCodeInfo() {
560 #if V8_TARGET_ARCH_IA32
561   const char arch[] = "ia32";
562 #elif V8_TARGET_ARCH_X64 && V8_TARGET_ARCH_64_BIT
563   const char arch[] = "x64";
564 #elif V8_TARGET_ARCH_X64 && V8_TARGET_ARCH_32_BIT
565   const char arch[] = "x32";
566 #elif V8_TARGET_ARCH_ARM
567   const char arch[] = "arm";
568 #elif V8_TARGET_ARCH_PPC
569   const char arch[] = "ppc";
570 #elif V8_TARGET_ARCH_MIPS
571   const char arch[] = "mips";
572 #elif V8_TARGET_ARCH_ARM64
573   const char arch[] = "arm64";
574 #elif V8_TARGET_ARCH_S390
575   const char arch[] = "s390";
576 #else
577   const char arch[] = "unknown";
578 #endif
579   LogWriteBytes(arch, sizeof(arch));
580 }
581 
LogRecordedBuffer(AbstractCode * code,SharedFunctionInfo *,const char * name,int length)582 void LowLevelLogger::LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo*,
583                                        const char* name, int length) {
584   CodeCreateStruct event;
585   event.name_size = length;
586   event.code_address = code->InstructionStart();
587   event.code_size = code->InstructionSize();
588   LogWriteStruct(event);
589   LogWriteBytes(name, length);
590   LogWriteBytes(reinterpret_cast<const char*>(code->InstructionStart()),
591                 code->InstructionSize());
592 }
593 
LogRecordedBuffer(const wasm::WasmCode * code,const char * name,int length)594 void LowLevelLogger::LogRecordedBuffer(const wasm::WasmCode* code,
595                                        const char* name, int length) {
596   CodeCreateStruct event;
597   event.name_size = length;
598   event.code_address = code->instruction_start();
599   event.code_size = code->instructions().length();
600   LogWriteStruct(event);
601   LogWriteBytes(name, length);
602   LogWriteBytes(reinterpret_cast<const char*>(code->instruction_start()),
603                 code->instructions().length());
604 }
605 
CodeMoveEvent(AbstractCode * from,AbstractCode * to)606 void LowLevelLogger::CodeMoveEvent(AbstractCode* from, AbstractCode* to) {
607   CodeMoveStruct event;
608   event.from_address = from->InstructionStart();
609   event.to_address = to->InstructionStart();
610   LogWriteStruct(event);
611 }
612 
613 
LogWriteBytes(const char * bytes,int size)614 void LowLevelLogger::LogWriteBytes(const char* bytes, int size) {
615   size_t rv = fwrite(bytes, 1, size, ll_output_handle_);
616   DCHECK(static_cast<size_t>(size) == rv);
617   USE(rv);
618 }
619 
620 
CodeMovingGCEvent()621 void LowLevelLogger::CodeMovingGCEvent() {
622   const char tag = kCodeMovingGCTag;
623 
624   LogWriteBytes(&tag, sizeof(tag));
625 }
626 
627 class JitLogger : public CodeEventLogger {
628  public:
629   JitLogger(Isolate* isolate, JitCodeEventHandler code_event_handler);
630 
631   void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override;
CodeDisableOptEvent(AbstractCode * code,SharedFunctionInfo * shared)632   void CodeDisableOptEvent(AbstractCode* code,
633                            SharedFunctionInfo* shared) override {}
634   void AddCodeLinePosInfoEvent(void* jit_handler_data, int pc_offset,
635                                int position,
636                                JitCodeEvent::PositionType position_type);
637 
638   void* StartCodePosInfoEvent();
639   void EndCodePosInfoEvent(Address start_address, void* jit_handler_data);
640 
641  private:
642   void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
643                          const char* name, int length) override;
644   void LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
645                          int length) override;
646 
647   JitCodeEventHandler code_event_handler_;
648   base::Mutex logger_mutex_;
649 };
650 
JitLogger(Isolate * isolate,JitCodeEventHandler code_event_handler)651 JitLogger::JitLogger(Isolate* isolate, JitCodeEventHandler code_event_handler)
652     : CodeEventLogger(isolate), code_event_handler_(code_event_handler) {}
653 
LogRecordedBuffer(AbstractCode * code,SharedFunctionInfo * shared,const char * name,int length)654 void JitLogger::LogRecordedBuffer(AbstractCode* code,
655                                   SharedFunctionInfo* shared, const char* name,
656                                   int length) {
657   JitCodeEvent event;
658   memset(&event, 0, sizeof(event));
659   event.type = JitCodeEvent::CODE_ADDED;
660   event.code_start = reinterpret_cast<void*>(code->InstructionStart());
661   event.code_type =
662       code->IsCode() ? JitCodeEvent::JIT_CODE : JitCodeEvent::BYTE_CODE;
663   event.code_len = code->InstructionSize();
664   Handle<SharedFunctionInfo> shared_function_handle;
665   if (shared && shared->script()->IsScript()) {
666     shared_function_handle =
667         Handle<SharedFunctionInfo>(shared, shared->GetIsolate());
668   }
669   event.script = ToApiHandle<v8::UnboundScript>(shared_function_handle);
670   event.name.str = name;
671   event.name.len = length;
672   event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
673   code_event_handler_(&event);
674 }
675 
LogRecordedBuffer(const wasm::WasmCode * code,const char * name,int length)676 void JitLogger::LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
677                                   int length) {
678   JitCodeEvent event;
679   memset(&event, 0, sizeof(event));
680   event.type = JitCodeEvent::CODE_ADDED;
681   event.code_type = JitCodeEvent::JIT_CODE;
682   event.code_start = code->instructions().start();
683   event.code_len = code->instructions().length();
684   event.name.str = name;
685   event.name.len = length;
686   event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
687   code_event_handler_(&event);
688 }
689 
CodeMoveEvent(AbstractCode * from,AbstractCode * to)690 void JitLogger::CodeMoveEvent(AbstractCode* from, AbstractCode* to) {
691   base::LockGuard<base::Mutex> guard(&logger_mutex_);
692 
693   JitCodeEvent event;
694   event.type = JitCodeEvent::CODE_MOVED;
695   event.code_type =
696       from->IsCode() ? JitCodeEvent::JIT_CODE : JitCodeEvent::BYTE_CODE;
697   event.code_start = reinterpret_cast<void*>(from->InstructionStart());
698   event.code_len = from->InstructionSize();
699   event.new_code_start = reinterpret_cast<void*>(to->InstructionStart());
700   event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
701 
702   code_event_handler_(&event);
703 }
704 
AddCodeLinePosInfoEvent(void * jit_handler_data,int pc_offset,int position,JitCodeEvent::PositionType position_type)705 void JitLogger::AddCodeLinePosInfoEvent(
706     void* jit_handler_data,
707     int pc_offset,
708     int position,
709     JitCodeEvent::PositionType position_type) {
710   JitCodeEvent event;
711   memset(&event, 0, sizeof(event));
712   event.type = JitCodeEvent::CODE_ADD_LINE_POS_INFO;
713   event.user_data = jit_handler_data;
714   event.line_info.offset = pc_offset;
715   event.line_info.pos = position;
716   event.line_info.position_type = position_type;
717   event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
718 
719   code_event_handler_(&event);
720 }
721 
722 
StartCodePosInfoEvent()723 void* JitLogger::StartCodePosInfoEvent() {
724   JitCodeEvent event;
725   memset(&event, 0, sizeof(event));
726   event.type = JitCodeEvent::CODE_START_LINE_INFO_RECORDING;
727   event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
728 
729   code_event_handler_(&event);
730   return event.user_data;
731 }
732 
EndCodePosInfoEvent(Address start_address,void * jit_handler_data)733 void JitLogger::EndCodePosInfoEvent(Address start_address,
734                                     void* jit_handler_data) {
735   JitCodeEvent event;
736   memset(&event, 0, sizeof(event));
737   event.type = JitCodeEvent::CODE_END_LINE_INFO_RECORDING;
738   event.code_start = reinterpret_cast<void*>(start_address);
739   event.user_data = jit_handler_data;
740   event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
741 
742   code_event_handler_(&event);
743 }
744 
745 
746 // TODO(lpy): Keeping sampling thread inside V8 is a workaround currently,
747 // the reason is to reduce code duplication during migration to sampler library,
748 // sampling thread, as well as the sampler, will be moved to D8 eventually.
749 class SamplingThread : public base::Thread {
750  public:
751   static const int kSamplingThreadStackSize = 64 * KB;
752 
SamplingThread(sampler::Sampler * sampler,int interval_microseconds)753   SamplingThread(sampler::Sampler* sampler, int interval_microseconds)
754       : base::Thread(
755             base::Thread::Options("SamplingThread", kSamplingThreadStackSize)),
756         sampler_(sampler),
757         interval_microseconds_(interval_microseconds) {}
Run()758   void Run() override {
759     while (sampler_->IsProfiling()) {
760       sampler_->DoSample();
761       base::OS::Sleep(
762           base::TimeDelta::FromMicroseconds(interval_microseconds_));
763     }
764   }
765 
766  private:
767   sampler::Sampler* sampler_;
768   const int interval_microseconds_;
769 };
770 
771 
772 // The Profiler samples pc and sp values for the main thread.
773 // Each sample is appended to a circular buffer.
774 // An independent thread removes data and writes it to the log.
775 // This design minimizes the time spent in the sampler.
776 //
777 class Profiler: public base::Thread {
778  public:
779   explicit Profiler(Isolate* isolate);
780   void Engage();
781   void Disengage();
782 
783   // Inserts collected profiling data into buffer.
Insert(v8::TickSample * sample)784   void Insert(v8::TickSample* sample) {
785     if (paused_)
786       return;
787 
788     if (Succ(head_) == static_cast<int>(base::Relaxed_Load(&tail_))) {
789       overflow_ = true;
790     } else {
791       buffer_[head_] = *sample;
792       head_ = Succ(head_);
793       buffer_semaphore_.Signal();  // Tell we have an element.
794     }
795   }
796 
797   virtual void Run();
798 
799   // Pause and Resume TickSample data collection.
Pause()800   void Pause() { paused_ = true; }
Resume()801   void Resume() { paused_ = false; }
802 
803  private:
804   // Waits for a signal and removes profiling data.
Remove(v8::TickSample * sample)805   bool Remove(v8::TickSample* sample) {
806     buffer_semaphore_.Wait();  // Wait for an element.
807     *sample = buffer_[base::Relaxed_Load(&tail_)];
808     bool result = overflow_;
809     base::Relaxed_Store(
810         &tail_, static_cast<base::Atomic32>(Succ(base::Relaxed_Load(&tail_))));
811     overflow_ = false;
812     return result;
813   }
814 
815   // Returns the next index in the cyclic buffer.
Succ(int index)816   int Succ(int index) { return (index + 1) % kBufferSize; }
817 
818   Isolate* isolate_;
819   // Cyclic buffer for communicating profiling samples
820   // between the signal handler and the worker thread.
821   static const int kBufferSize = 128;
822   v8::TickSample buffer_[kBufferSize];  // Buffer storage.
823   int head_;  // Index to the buffer head.
824   base::Atomic32 tail_;             // Index to the buffer tail.
825   bool overflow_;  // Tell whether a buffer overflow has occurred.
826   // Semaphore used for buffer synchronization.
827   base::Semaphore buffer_semaphore_;
828 
829   // Tells whether profiler is engaged, that is, processing thread is stated.
830   bool engaged_;
831 
832   // Tells whether worker thread should continue running.
833   base::Atomic32 running_;
834 
835   // Tells whether we are currently recording tick samples.
836   bool paused_;
837 };
838 
839 
840 //
841 // Ticker used to provide ticks to the profiler and the sliding state
842 // window.
843 //
844 class Ticker: public sampler::Sampler {
845  public:
Ticker(Isolate * isolate,int interval_microseconds)846   Ticker(Isolate* isolate, int interval_microseconds)
847       : sampler::Sampler(reinterpret_cast<v8::Isolate*>(isolate)),
848         profiler_(nullptr),
849         sampling_thread_(new SamplingThread(this, interval_microseconds)) {}
850 
~Ticker()851   ~Ticker() {
852     if (IsActive()) Stop();
853     delete sampling_thread_;
854   }
855 
SetProfiler(Profiler * profiler)856   void SetProfiler(Profiler* profiler) {
857     DCHECK_NULL(profiler_);
858     profiler_ = profiler;
859     IncreaseProfilingDepth();
860     if (!IsActive()) Start();
861     sampling_thread_->StartSynchronously();
862   }
863 
ClearProfiler()864   void ClearProfiler() {
865     profiler_ = nullptr;
866     if (IsActive()) Stop();
867     DecreaseProfilingDepth();
868     sampling_thread_->Join();
869   }
870 
SampleStack(const v8::RegisterState & state)871   void SampleStack(const v8::RegisterState& state) override {
872     if (!profiler_) return;
873     Isolate* isolate = reinterpret_cast<Isolate*>(this->isolate());
874     TickSample sample;
875     sample.Init(isolate, state, TickSample::kIncludeCEntryFrame, true);
876     profiler_->Insert(&sample);
877   }
878 
879  private:
880   Profiler* profiler_;
881   SamplingThread* sampling_thread_;
882 };
883 
884 //
885 // Profiler implementation when invoking with --prof.
886 //
Profiler(Isolate * isolate)887 Profiler::Profiler(Isolate* isolate)
888     : base::Thread(Options("v8:Profiler")),
889       isolate_(isolate),
890       head_(0),
891       overflow_(false),
892       buffer_semaphore_(0),
893       engaged_(false),
894       paused_(false) {
895   base::Relaxed_Store(&tail_, 0);
896   base::Relaxed_Store(&running_, 0);
897 }
898 
899 
Engage()900 void Profiler::Engage() {
901   if (engaged_) return;
902   engaged_ = true;
903 
904   std::vector<base::OS::SharedLibraryAddress> addresses =
905       base::OS::GetSharedLibraryAddresses();
906   for (const auto& address : addresses) {
907     LOG(isolate_, SharedLibraryEvent(address.library_path, address.start,
908                                      address.end, address.aslr_slide));
909   }
910 
911   // Start thread processing the profiler buffer.
912   base::Relaxed_Store(&running_, 1);
913   Start();
914 
915   // Register to get ticks.
916   Logger* logger = isolate_->logger();
917   logger->ticker_->SetProfiler(this);
918 
919   logger->ProfilerBeginEvent();
920 }
921 
922 
Disengage()923 void Profiler::Disengage() {
924   if (!engaged_) return;
925 
926   // Stop receiving ticks.
927   isolate_->logger()->ticker_->ClearProfiler();
928 
929   // Terminate the worker thread by setting running_ to false,
930   // inserting a fake element in the queue and then wait for
931   // the thread to terminate.
932   base::Relaxed_Store(&running_, 0);
933   v8::TickSample sample;
934   // Reset 'paused_' flag, otherwise semaphore may not be signalled.
935   Resume();
936   Insert(&sample);
937   Join();
938 
939   LOG(isolate_, UncheckedStringEvent("profiler", "end"));
940 }
941 
942 
Run()943 void Profiler::Run() {
944   v8::TickSample sample;
945   bool overflow = Remove(&sample);
946   while (base::Relaxed_Load(&running_)) {
947     LOG(isolate_, TickEvent(&sample, overflow));
948     overflow = Remove(&sample);
949   }
950 }
951 
952 
953 //
954 // Logger class implementation.
955 //
956 
Logger(Isolate * isolate)957 Logger::Logger(Isolate* isolate)
958     : isolate_(isolate),
959       ticker_(nullptr),
960       profiler_(nullptr),
961       log_events_(nullptr),
962       is_logging_(false),
963       log_(nullptr),
964       perf_basic_logger_(nullptr),
965       perf_jit_logger_(nullptr),
966       ll_logger_(nullptr),
967       jit_logger_(nullptr),
968       is_initialized_(false),
969       existing_code_logger_(isolate) {}
970 
~Logger()971 Logger::~Logger() {
972   delete log_;
973 }
974 
AddCodeEventListener(CodeEventListener * listener)975 void Logger::AddCodeEventListener(CodeEventListener* listener) {
976   bool result = isolate_->code_event_dispatcher()->AddListener(listener);
977   CHECK(result);
978 }
979 
RemoveCodeEventListener(CodeEventListener * listener)980 void Logger::RemoveCodeEventListener(CodeEventListener* listener) {
981   isolate_->code_event_dispatcher()->RemoveListener(listener);
982 }
983 
ProfilerBeginEvent()984 void Logger::ProfilerBeginEvent() {
985   if (!log_->IsEnabled()) return;
986   Log::MessageBuilder msg(log_);
987   msg << "profiler" << kNext << "begin" << kNext << FLAG_prof_sampling_interval;
988   msg.WriteToLogFile();
989 }
990 
991 
StringEvent(const char * name,const char * value)992 void Logger::StringEvent(const char* name, const char* value) {
993   if (FLAG_log) UncheckedStringEvent(name, value);
994 }
995 
996 
UncheckedStringEvent(const char * name,const char * value)997 void Logger::UncheckedStringEvent(const char* name, const char* value) {
998   if (!log_->IsEnabled()) return;
999   Log::MessageBuilder msg(log_);
1000   msg << name << kNext << value;
1001   msg.WriteToLogFile();
1002 }
1003 
1004 
IntPtrTEvent(const char * name,intptr_t value)1005 void Logger::IntPtrTEvent(const char* name, intptr_t value) {
1006   if (FLAG_log) UncheckedIntPtrTEvent(name, value);
1007 }
1008 
1009 
UncheckedIntPtrTEvent(const char * name,intptr_t value)1010 void Logger::UncheckedIntPtrTEvent(const char* name, intptr_t value) {
1011   if (!log_->IsEnabled()) return;
1012   Log::MessageBuilder msg(log_);
1013   msg << name << kNext;
1014   msg.AppendFormatString("%" V8PRIdPTR, value);
1015   msg.WriteToLogFile();
1016 }
1017 
1018 
HandleEvent(const char * name,Object ** location)1019 void Logger::HandleEvent(const char* name, Object** location) {
1020   if (!log_->IsEnabled() || !FLAG_log_handles) return;
1021   Log::MessageBuilder msg(log_);
1022   msg << name << kNext << static_cast<void*>(location);
1023   msg.WriteToLogFile();
1024 }
1025 
1026 
ApiSecurityCheck()1027 void Logger::ApiSecurityCheck() {
1028   if (!log_->IsEnabled() || !FLAG_log_api) return;
1029   Log::MessageBuilder msg(log_);
1030   msg << "api" << kNext << "check-security";
1031   msg.WriteToLogFile();
1032 }
1033 
SharedLibraryEvent(const std::string & library_path,uintptr_t start,uintptr_t end,intptr_t aslr_slide)1034 void Logger::SharedLibraryEvent(const std::string& library_path,
1035                                 uintptr_t start, uintptr_t end,
1036                                 intptr_t aslr_slide) {
1037   if (!log_->IsEnabled() || !FLAG_prof_cpp) return;
1038   Log::MessageBuilder msg(log_);
1039   msg << "shared-library" << kNext << library_path.c_str() << kNext
1040       << reinterpret_cast<void*>(start) << kNext << reinterpret_cast<void*>(end)
1041       << kNext << aslr_slide;
1042   msg.WriteToLogFile();
1043 }
1044 
CodeDeoptEvent(Code * code,DeoptimizeKind kind,Address pc,int fp_to_sp_delta)1045 void Logger::CodeDeoptEvent(Code* code, DeoptimizeKind kind, Address pc,
1046                             int fp_to_sp_delta) {
1047   if (!log_->IsEnabled()) return;
1048   Deoptimizer::DeoptInfo info = Deoptimizer::GetDeoptInfo(code, pc);
1049   Log::MessageBuilder msg(log_);
1050   msg << "code-deopt" << kNext << timer_.Elapsed().InMicroseconds() << kNext
1051       << code->CodeSize() << kNext
1052       << reinterpret_cast<void*>(code->InstructionStart());
1053 
1054   // Deoptimization position.
1055   std::ostringstream deopt_location;
1056   int inlining_id = -1;
1057   int script_offset = -1;
1058   if (info.position.IsKnown()) {
1059     info.position.Print(deopt_location, code);
1060     inlining_id = info.position.InliningId();
1061     script_offset = info.position.ScriptOffset();
1062   } else {
1063     deopt_location << "<unknown>";
1064   }
1065   msg << kNext << inlining_id << kNext << script_offset << kNext;
1066   msg << Deoptimizer::MessageFor(kind) << kNext;
1067   msg << deopt_location.str().c_str() << kNext
1068       << DeoptimizeReasonToString(info.deopt_reason);
1069   msg.WriteToLogFile();
1070 }
1071 
1072 
CurrentTimeEvent()1073 void Logger::CurrentTimeEvent() {
1074   if (!log_->IsEnabled()) return;
1075   DCHECK(FLAG_log_internal_timer_events);
1076   Log::MessageBuilder msg(log_);
1077   msg << "current-time" << kNext << timer_.Elapsed().InMicroseconds();
1078   msg.WriteToLogFile();
1079 }
1080 
1081 
TimerEvent(Logger::StartEnd se,const char * name)1082 void Logger::TimerEvent(Logger::StartEnd se, const char* name) {
1083   if (!log_->IsEnabled()) return;
1084   Log::MessageBuilder msg(log_);
1085   switch (se) {
1086     case START:
1087       msg << "timer-event-start";
1088       break;
1089     case END:
1090       msg << "timer-event-end";
1091       break;
1092     case STAMP:
1093       msg << "timer-event";
1094   }
1095   msg << kNext << name << kNext << timer_.Elapsed().InMicroseconds();
1096   msg.WriteToLogFile();
1097 }
1098 
1099 // static
EnterExternal(Isolate * isolate)1100 void Logger::EnterExternal(Isolate* isolate) {
1101   DCHECK(FLAG_log_internal_timer_events);
1102   LOG(isolate, TimerEvent(START, TimerEventExternal::name()));
1103   DCHECK(isolate->current_vm_state() == JS);
1104   isolate->set_current_vm_state(EXTERNAL);
1105 }
1106 
1107 // static
LeaveExternal(Isolate * isolate)1108 void Logger::LeaveExternal(Isolate* isolate) {
1109   DCHECK(FLAG_log_internal_timer_events);
1110   LOG(isolate, TimerEvent(END, TimerEventExternal::name()));
1111   DCHECK(isolate->current_vm_state() == EXTERNAL);
1112   isolate->set_current_vm_state(JS);
1113 }
1114 
1115 // Instantiate template methods.
1116 #define V(TimerName, expose)                                           \
1117   template void TimerEventScope<TimerEvent##TimerName>::LogTimerEvent( \
1118       Logger::StartEnd se);
TIMER_EVENTS_LIST(V)1119 TIMER_EVENTS_LIST(V)
1120 #undef V
1121 
1122 void Logger::ApiNamedPropertyAccess(const char* tag, JSObject* holder,
1123                                     Object* property_name) {
1124   DCHECK(property_name->IsName());
1125   if (!log_->IsEnabled() || !FLAG_log_api) return;
1126   Log::MessageBuilder msg(log_);
1127   msg << "api" << kNext << tag << kNext << holder->class_name() << kNext
1128       << Name::cast(property_name);
1129   msg.WriteToLogFile();
1130 }
1131 
ApiIndexedPropertyAccess(const char * tag,JSObject * holder,uint32_t index)1132 void Logger::ApiIndexedPropertyAccess(const char* tag,
1133                                       JSObject* holder,
1134                                       uint32_t index) {
1135   if (!log_->IsEnabled() || !FLAG_log_api) return;
1136   Log::MessageBuilder msg(log_);
1137   msg << "api" << kNext << tag << kNext << holder->class_name() << kNext
1138       << index;
1139   msg.WriteToLogFile();
1140 }
1141 
1142 
ApiObjectAccess(const char * tag,JSObject * object)1143 void Logger::ApiObjectAccess(const char* tag, JSObject* object) {
1144   if (!log_->IsEnabled() || !FLAG_log_api) return;
1145   Log::MessageBuilder msg(log_);
1146   msg << "api" << kNext << tag << kNext << object->class_name();
1147   msg.WriteToLogFile();
1148 }
1149 
1150 
ApiEntryCall(const char * name)1151 void Logger::ApiEntryCall(const char* name) {
1152   if (!log_->IsEnabled() || !FLAG_log_api) return;
1153   Log::MessageBuilder msg(log_);
1154   msg << "api" << kNext << name;
1155   msg.WriteToLogFile();
1156 }
1157 
1158 
NewEvent(const char * name,void * object,size_t size)1159 void Logger::NewEvent(const char* name, void* object, size_t size) {
1160   if (!log_->IsEnabled() || !FLAG_log) return;
1161   Log::MessageBuilder msg(log_);
1162   msg << "new" << kNext << name << kNext << object << kNext
1163       << static_cast<unsigned int>(size);
1164   msg.WriteToLogFile();
1165 }
1166 
1167 
DeleteEvent(const char * name,void * object)1168 void Logger::DeleteEvent(const char* name, void* object) {
1169   if (!log_->IsEnabled() || !FLAG_log) return;
1170   Log::MessageBuilder msg(log_);
1171   msg << "delete" << kNext << name << kNext << object;
1172   msg.WriteToLogFile();
1173 }
1174 
1175 
CallbackEventInternal(const char * prefix,Name * name,Address entry_point)1176 void Logger::CallbackEventInternal(const char* prefix, Name* name,
1177                                    Address entry_point) {
1178   if (!FLAG_log_code || !log_->IsEnabled()) return;
1179   Log::MessageBuilder msg(log_);
1180   msg << kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT] << kNext
1181       << kLogEventsNames[CodeEventListener::CALLBACK_TAG] << kNext << -2
1182       << kNext << timer_.Elapsed().InMicroseconds() << kNext
1183       << reinterpret_cast<void*>(entry_point) << kNext << 1 << kNext << prefix
1184       << name;
1185   msg.WriteToLogFile();
1186 }
1187 
1188 
CallbackEvent(Name * name,Address entry_point)1189 void Logger::CallbackEvent(Name* name, Address entry_point) {
1190   CallbackEventInternal("", name, entry_point);
1191 }
1192 
1193 
GetterCallbackEvent(Name * name,Address entry_point)1194 void Logger::GetterCallbackEvent(Name* name, Address entry_point) {
1195   CallbackEventInternal("get ", name, entry_point);
1196 }
1197 
1198 
SetterCallbackEvent(Name * name,Address entry_point)1199 void Logger::SetterCallbackEvent(Name* name, Address entry_point) {
1200   CallbackEventInternal("set ", name, entry_point);
1201 }
1202 
1203 namespace {
1204 
AppendCodeCreateHeader(Log::MessageBuilder & msg,CodeEventListener::LogEventsAndTags tag,AbstractCode::Kind kind,uint8_t * address,int size,base::ElapsedTimer * timer)1205 void AppendCodeCreateHeader(Log::MessageBuilder& msg,
1206                             CodeEventListener::LogEventsAndTags tag,
1207                             AbstractCode::Kind kind, uint8_t* address, int size,
1208                             base::ElapsedTimer* timer) {
1209   msg << kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT]
1210       << Logger::kNext << kLogEventsNames[tag] << Logger::kNext << kind
1211       << Logger::kNext << timer->Elapsed().InMicroseconds() << Logger::kNext
1212       << reinterpret_cast<void*>(address) << Logger::kNext << size
1213       << Logger::kNext;
1214 }
1215 
AppendCodeCreateHeader(Log::MessageBuilder & msg,CodeEventListener::LogEventsAndTags tag,AbstractCode * code,base::ElapsedTimer * timer)1216 void AppendCodeCreateHeader(Log::MessageBuilder& msg,
1217                             CodeEventListener::LogEventsAndTags tag,
1218                             AbstractCode* code, base::ElapsedTimer* timer) {
1219   AppendCodeCreateHeader(msg, tag, code->kind(),
1220                          reinterpret_cast<uint8_t*>(code->InstructionStart()),
1221                          code->InstructionSize(), timer);
1222 }
1223 
1224 }  // namespace
1225 
CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,AbstractCode * code,const char * comment)1226 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
1227                              AbstractCode* code, const char* comment) {
1228   if (!is_listening_to_code_events()) return;
1229   if (!FLAG_log_code || !log_->IsEnabled()) return;
1230   Log::MessageBuilder msg(log_);
1231   AppendCodeCreateHeader(msg, tag, code, &timer_);
1232   msg << comment;
1233   msg.WriteToLogFile();
1234 }
1235 
CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,AbstractCode * code,Name * name)1236 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
1237                              AbstractCode* code, Name* name) {
1238   if (!is_listening_to_code_events()) return;
1239   if (!FLAG_log_code || !log_->IsEnabled()) return;
1240   Log::MessageBuilder msg(log_);
1241   AppendCodeCreateHeader(msg, tag, code, &timer_);
1242   msg << name;
1243   msg.WriteToLogFile();
1244 }
1245 
CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,AbstractCode * code,SharedFunctionInfo * shared,Name * name)1246 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
1247                              AbstractCode* code, SharedFunctionInfo* shared,
1248                              Name* name) {
1249   if (!is_listening_to_code_events()) return;
1250   if (!FLAG_log_code || !log_->IsEnabled()) return;
1251   if (code == AbstractCode::cast(
1252                   isolate_->builtins()->builtin(Builtins::kCompileLazy))) {
1253     return;
1254   }
1255 
1256   Log::MessageBuilder msg(log_);
1257   AppendCodeCreateHeader(msg, tag, code, &timer_);
1258   msg << name << kNext << reinterpret_cast<void*>(shared->address()) << kNext
1259       << ComputeMarker(shared, code);
1260   msg.WriteToLogFile();
1261 }
1262 
CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,const wasm::WasmCode * code,wasm::WasmName name)1263 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
1264                              const wasm::WasmCode* code, wasm::WasmName name) {
1265   if (!is_listening_to_code_events()) return;
1266   if (!FLAG_log_code || !log_->IsEnabled()) return;
1267   Log::MessageBuilder msg(log_);
1268   AppendCodeCreateHeader(msg, tag, AbstractCode::Kind::WASM_FUNCTION,
1269                          code->instructions().start(),
1270                          code->instructions().length(), &timer_);
1271   if (name.is_empty()) {
1272     msg << "<unknown wasm>";
1273   } else {
1274     msg.AppendString(name);
1275   }
1276   // We have to add two extra fields that allow the tick processor to group
1277   // events for the same wasm function, even if it gets compiled again. For
1278   // normal JS functions, we use the shared function info. For wasm, the pointer
1279   // to the native module + function index works well enough.
1280   // TODO(herhut) Clean up the tick processor code instead.
1281   void* tag_ptr =
1282       reinterpret_cast<byte*>(code->native_module()) + code->index();
1283   msg << kNext << tag_ptr << kNext << ComputeMarker(code);
1284   msg.WriteToLogFile();
1285 }
1286 
1287 // Although, it is possible to extract source and line from
1288 // the SharedFunctionInfo object, we left it to caller
1289 // to leave logging functions free from heap allocations.
CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,AbstractCode * code,SharedFunctionInfo * shared,Name * source,int line,int column)1290 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
1291                              AbstractCode* code, SharedFunctionInfo* shared,
1292                              Name* source, int line, int column) {
1293   if (!is_listening_to_code_events()) return;
1294   if (!FLAG_log_code || !log_->IsEnabled()) return;
1295   {
1296     Log::MessageBuilder msg(log_);
1297     AppendCodeCreateHeader(msg, tag, code, &timer_);
1298     msg << shared->DebugName() << " " << source << ":" << line << ":" << column
1299         << kNext << reinterpret_cast<void*>(shared->address()) << kNext
1300         << ComputeMarker(shared, code);
1301     msg.WriteToLogFile();
1302   }
1303 
1304   if (!FLAG_log_source_code) return;
1305   Object* script_object = shared->script();
1306   if (!script_object->IsScript()) return;
1307   Script* script = Script::cast(script_object);
1308   if (!EnsureLogScriptSource(script)) return;
1309 
1310   // We log source code information in the form:
1311   //
1312   // code-source-info <addr>,<script>,<start>,<end>,<pos>,<inline-pos>,<fns>
1313   //
1314   // where
1315   //   <addr> is code object address
1316   //   <script> is script id
1317   //   <start> is the starting position inside the script
1318   //   <end> is the end position inside the script
1319   //   <pos> is source position table encoded in the string,
1320   //      it is a sequence of C<code-offset>O<script-offset>[I<inlining-id>]
1321   //      where
1322   //        <code-offset> is the offset within the code object
1323   //        <script-offset> is the position within the script
1324   //        <inlining-id> is the offset in the <inlining> table
1325   //   <inlining> table is a sequence of strings of the form
1326   //      F<function-id>O<script-offset>[I<inlining-id>
1327   //      where
1328   //         <function-id> is an index into the <fns> function table
1329   //   <fns> is the function table encoded as a sequence of strings
1330   //      S<shared-function-info-address>
1331   Log::MessageBuilder msg(log_);
1332   msg << "code-source-info" << kNext
1333       << reinterpret_cast<void*>(code->InstructionStart()) << kNext
1334       << script->id() << kNext << shared->StartPosition() << kNext
1335       << shared->EndPosition() << kNext;
1336 
1337   SourcePositionTableIterator iterator(code->source_position_table());
1338   bool is_first = true;
1339   bool hasInlined = false;
1340   for (; !iterator.done(); iterator.Advance()) {
1341     if (is_first) {
1342       is_first = false;
1343     }
1344     SourcePosition pos = iterator.source_position();
1345     msg << "C" << iterator.code_offset() << "O" << pos.ScriptOffset();
1346     if (pos.isInlined()) {
1347       msg << "I" << pos.InliningId();
1348       hasInlined = true;
1349     }
1350   }
1351   msg << kNext;
1352   int maxInlinedId = -1;
1353   if (hasInlined) {
1354     PodArray<InliningPosition>* inlining_positions =
1355         DeoptimizationData::cast(Code::cast(code)->deoptimization_data())
1356             ->InliningPositions();
1357     for (int i = 0; i < inlining_positions->length(); i++) {
1358       InliningPosition inlining_pos = inlining_positions->get(i);
1359       msg << "F";
1360       if (inlining_pos.inlined_function_id != -1) {
1361         msg << inlining_pos.inlined_function_id;
1362         if (inlining_pos.inlined_function_id > maxInlinedId) {
1363           maxInlinedId = inlining_pos.inlined_function_id;
1364         }
1365       }
1366       SourcePosition pos = inlining_pos.position;
1367       msg << "O" << pos.ScriptOffset();
1368       if (pos.isInlined()) {
1369         msg << "I" << pos.InliningId();
1370       }
1371     }
1372   }
1373   msg << kNext;
1374   if (hasInlined) {
1375     DeoptimizationData* deopt_data =
1376         DeoptimizationData::cast(Code::cast(code)->deoptimization_data());
1377 
1378     msg << std::hex;
1379     for (int i = 0; i <= maxInlinedId; i++) {
1380       msg << "S"
1381           << reinterpret_cast<void*>(
1382                  deopt_data->GetInlinedFunction(i)->address());
1383     }
1384     msg << std::dec;
1385   }
1386   msg.WriteToLogFile();
1387 }
1388 
CodeDisableOptEvent(AbstractCode * code,SharedFunctionInfo * shared)1389 void Logger::CodeDisableOptEvent(AbstractCode* code,
1390                                  SharedFunctionInfo* shared) {
1391   if (!is_listening_to_code_events()) return;
1392   if (!FLAG_log_code || !log_->IsEnabled()) return;
1393   Log::MessageBuilder msg(log_);
1394   msg << kLogEventsNames[CodeEventListener::CODE_DISABLE_OPT_EVENT] << kNext
1395       << shared->DebugName() << kNext
1396       << GetBailoutReason(shared->disable_optimization_reason());
1397   msg.WriteToLogFile();
1398 }
1399 
1400 
CodeMovingGCEvent()1401 void Logger::CodeMovingGCEvent() {
1402   if (!is_listening_to_code_events()) return;
1403   if (!log_->IsEnabled() || !FLAG_ll_prof) return;
1404   base::OS::SignalCodeMovingGC();
1405 }
1406 
RegExpCodeCreateEvent(AbstractCode * code,String * source)1407 void Logger::RegExpCodeCreateEvent(AbstractCode* code, String* source) {
1408   if (!is_listening_to_code_events()) return;
1409   if (!FLAG_log_code || !log_->IsEnabled()) return;
1410   Log::MessageBuilder msg(log_);
1411   AppendCodeCreateHeader(msg, CodeEventListener::REG_EXP_TAG, code, &timer_);
1412   msg << source;
1413   msg.WriteToLogFile();
1414 }
1415 
CodeMoveEvent(AbstractCode * from,AbstractCode * to)1416 void Logger::CodeMoveEvent(AbstractCode* from, AbstractCode* to) {
1417   if (!is_listening_to_code_events()) return;
1418   MoveEventInternal(CodeEventListener::CODE_MOVE_EVENT, from->address(),
1419                     to->address());
1420 }
1421 
1422 namespace {
1423 
CodeLinePosEvent(JitLogger * jit_logger,Address code_start,SourcePositionTableIterator & iter)1424 void CodeLinePosEvent(JitLogger* jit_logger, Address code_start,
1425                       SourcePositionTableIterator& iter) {
1426   if (jit_logger) {
1427     void* jit_handler_data = jit_logger->StartCodePosInfoEvent();
1428     for (; !iter.done(); iter.Advance()) {
1429       if (iter.is_statement()) {
1430         jit_logger->AddCodeLinePosInfoEvent(
1431             jit_handler_data, iter.code_offset(),
1432             iter.source_position().ScriptOffset(),
1433             JitCodeEvent::STATEMENT_POSITION);
1434       }
1435       jit_logger->AddCodeLinePosInfoEvent(jit_handler_data, iter.code_offset(),
1436                                           iter.source_position().ScriptOffset(),
1437                                           JitCodeEvent::POSITION);
1438     }
1439     jit_logger->EndCodePosInfoEvent(code_start, jit_handler_data);
1440   }
1441 }
1442 
1443 }  // namespace
1444 
CodeLinePosInfoRecordEvent(Address code_start,ByteArray * source_position_table)1445 void Logger::CodeLinePosInfoRecordEvent(Address code_start,
1446                                         ByteArray* source_position_table) {
1447   SourcePositionTableIterator iter(source_position_table);
1448   CodeLinePosEvent(jit_logger_, code_start, iter);
1449 }
1450 
CodeLinePosInfoRecordEvent(Address code_start,Vector<const byte> source_position_table)1451 void Logger::CodeLinePosInfoRecordEvent(
1452     Address code_start, Vector<const byte> source_position_table) {
1453   SourcePositionTableIterator iter(source_position_table);
1454   CodeLinePosEvent(jit_logger_, code_start, iter);
1455 }
1456 
CodeNameEvent(Address addr,int pos,const char * code_name)1457 void Logger::CodeNameEvent(Address addr, int pos, const char* code_name) {
1458   if (code_name == nullptr) return;  // Not a code object.
1459   Log::MessageBuilder msg(log_);
1460   msg << kLogEventsNames[CodeEventListener::SNAPSHOT_CODE_NAME_EVENT] << kNext
1461       << pos << kNext << code_name;
1462   msg.WriteToLogFile();
1463 }
1464 
1465 
SharedFunctionInfoMoveEvent(Address from,Address to)1466 void Logger::SharedFunctionInfoMoveEvent(Address from, Address to) {
1467   if (!is_listening_to_code_events()) return;
1468   MoveEventInternal(CodeEventListener::SHARED_FUNC_MOVE_EVENT, from, to);
1469 }
1470 
MoveEventInternal(CodeEventListener::LogEventsAndTags event,Address from,Address to)1471 void Logger::MoveEventInternal(CodeEventListener::LogEventsAndTags event,
1472                                Address from, Address to) {
1473   if (!FLAG_log_code || !log_->IsEnabled()) return;
1474   Log::MessageBuilder msg(log_);
1475   msg << kLogEventsNames[event] << kNext << reinterpret_cast<void*>(from)
1476       << kNext << reinterpret_cast<void*>(to);
1477   msg.WriteToLogFile();
1478 }
1479 
1480 
ResourceEvent(const char * name,const char * tag)1481 void Logger::ResourceEvent(const char* name, const char* tag) {
1482   if (!log_->IsEnabled() || !FLAG_log) return;
1483   Log::MessageBuilder msg(log_);
1484   msg << name << kNext << tag << kNext;
1485 
1486   uint32_t sec, usec;
1487   if (base::OS::GetUserTime(&sec, &usec) != -1) {
1488     msg << sec << kNext << usec << kNext;
1489   }
1490   msg.AppendFormatString("%.0f",
1491                          V8::GetCurrentPlatform()->CurrentClockTimeMillis());
1492   msg.WriteToLogFile();
1493 }
1494 
1495 
SuspectReadEvent(Name * name,Object * obj)1496 void Logger::SuspectReadEvent(Name* name, Object* obj) {
1497   if (!log_->IsEnabled() || !FLAG_log_suspect) return;
1498   Log::MessageBuilder msg(log_);
1499   String* class_name = obj->IsJSObject()
1500                            ? JSObject::cast(obj)->class_name()
1501                            : ReadOnlyRoots(isolate_).empty_string();
1502   msg << "suspect-read" << kNext << class_name << kNext << name;
1503   msg.WriteToLogFile();
1504 }
1505 
1506 namespace {
AppendFunctionMessage(Log::MessageBuilder & msg,const char * reason,int script_id,double time_delta,int start_position,int end_position,base::ElapsedTimer * timer)1507 void AppendFunctionMessage(Log::MessageBuilder& msg, const char* reason,
1508                            int script_id, double time_delta, int start_position,
1509                            int end_position, base::ElapsedTimer* timer) {
1510   msg << "function" << Logger::kNext << reason << Logger::kNext << script_id
1511       << Logger::kNext << start_position << Logger::kNext << end_position
1512       << Logger::kNext << time_delta << Logger::kNext
1513       << timer->Elapsed().InMicroseconds() << Logger::kNext;
1514 }
1515 }  // namespace
1516 
FunctionEvent(const char * reason,int script_id,double time_delta,int start_position,int end_position,String * function_name)1517 void Logger::FunctionEvent(const char* reason, int script_id, double time_delta,
1518                            int start_position, int end_position,
1519                            String* function_name) {
1520   if (!log_->IsEnabled() || !FLAG_log_function_events) return;
1521   Log::MessageBuilder msg(log_);
1522   AppendFunctionMessage(msg, reason, script_id, time_delta, start_position,
1523                         end_position, &timer_);
1524   if (function_name) msg << function_name;
1525   msg.WriteToLogFile();
1526 }
1527 
FunctionEvent(const char * reason,int script_id,double time_delta,int start_position,int end_position,const char * function_name,size_t function_name_length)1528 void Logger::FunctionEvent(const char* reason, int script_id, double time_delta,
1529                            int start_position, int end_position,
1530                            const char* function_name,
1531                            size_t function_name_length) {
1532   if (!log_->IsEnabled() || !FLAG_log_function_events) return;
1533   Log::MessageBuilder msg(log_);
1534   AppendFunctionMessage(msg, reason, script_id, time_delta, start_position,
1535                         end_position, &timer_);
1536   if (function_name_length > 0) {
1537     msg.AppendString(function_name, function_name_length);
1538   }
1539   msg.WriteToLogFile();
1540 }
1541 
CompilationCacheEvent(const char * action,const char * cache_type,SharedFunctionInfo * sfi)1542 void Logger::CompilationCacheEvent(const char* action, const char* cache_type,
1543                                    SharedFunctionInfo* sfi) {
1544   if (!log_->IsEnabled() || !FLAG_log_function_events) return;
1545   Log::MessageBuilder msg(log_);
1546   int script_id = -1;
1547   if (sfi->script()->IsScript()) {
1548     script_id = Script::cast(sfi->script())->id();
1549   }
1550   msg << "compilation-cache" << Logger::kNext << action << Logger::kNext
1551       << cache_type << Logger::kNext << script_id << Logger::kNext
1552       << sfi->StartPosition() << Logger::kNext << sfi->EndPosition()
1553       << Logger::kNext << timer_.Elapsed().InMicroseconds();
1554   msg.WriteToLogFile();
1555 }
1556 
ScriptEvent(ScriptEventType type,int script_id)1557 void Logger::ScriptEvent(ScriptEventType type, int script_id) {
1558   if (!log_->IsEnabled() || !FLAG_log_function_events) return;
1559   Log::MessageBuilder msg(log_);
1560   msg << "script" << Logger::kNext;
1561   switch (type) {
1562     case ScriptEventType::kReserveId:
1563       msg << "reserve-id";
1564       break;
1565     case ScriptEventType::kCreate:
1566       msg << "create";
1567       break;
1568     case ScriptEventType::kDeserialize:
1569       msg << "deserialize";
1570       break;
1571     case ScriptEventType::kBackgroundCompile:
1572       msg << "background-compile";
1573       break;
1574     case ScriptEventType::kStreamingCompile:
1575       msg << "streaming-compile";
1576       break;
1577   }
1578   msg << Logger::kNext << script_id << Logger::kNext
1579       << timer_.Elapsed().InMicroseconds();
1580   msg.WriteToLogFile();
1581 }
1582 
ScriptDetails(Script * script)1583 void Logger::ScriptDetails(Script* script) {
1584   if (!log_->IsEnabled() || !FLAG_log_function_events) return;
1585   {
1586     Log::MessageBuilder msg(log_);
1587     msg << "script-details" << Logger::kNext << script->id() << Logger::kNext;
1588     if (script->name()->IsString()) {
1589       msg << String::cast(script->name());
1590     }
1591     msg << Logger::kNext << script->line_offset() << Logger::kNext
1592         << script->column_offset() << Logger::kNext;
1593     if (script->source_mapping_url()->IsString()) {
1594       msg << String::cast(script->source_mapping_url());
1595     }
1596     msg.WriteToLogFile();
1597   }
1598   EnsureLogScriptSource(script);
1599 }
1600 
EnsureLogScriptSource(Script * script)1601 bool Logger::EnsureLogScriptSource(Script* script) {
1602   if (!log_->IsEnabled()) return false;
1603   Log::MessageBuilder msg(log_);
1604   // Make sure the script is written to the log file.
1605   int script_id = script->id();
1606   if (logged_source_code_.find(script_id) != logged_source_code_.end()) {
1607     return false;
1608   }
1609   // This script has not been logged yet.
1610   logged_source_code_.insert(script_id);
1611   Object* source_object = script->source();
1612   if (!source_object->IsString()) return false;
1613   String* source_code = String::cast(source_object);
1614   msg << "script-source" << kNext << script_id << kNext;
1615 
1616   // Log the script name.
1617   if (script->name()->IsString()) {
1618     msg << String::cast(script->name()) << kNext;
1619   } else {
1620     msg << "<unknown>" << kNext;
1621   }
1622 
1623   // Log the source code.
1624   msg << source_code;
1625   msg.WriteToLogFile();
1626   return true;
1627 }
1628 
RuntimeCallTimerEvent()1629 void Logger::RuntimeCallTimerEvent() {
1630   RuntimeCallStats* stats = isolate_->counters()->runtime_call_stats();
1631   RuntimeCallCounter* counter = stats->current_counter();
1632   if (counter == nullptr) return;
1633   Log::MessageBuilder msg(log_);
1634   msg << "active-runtime-timer" << kNext << counter->name();
1635   msg.WriteToLogFile();
1636 }
1637 
TickEvent(v8::TickSample * sample,bool overflow)1638 void Logger::TickEvent(v8::TickSample* sample, bool overflow) {
1639   if (!log_->IsEnabled() || !FLAG_prof_cpp) return;
1640   if (V8_UNLIKELY(FLAG_runtime_stats ==
1641                   v8::tracing::TracingCategoryObserver::ENABLED_BY_NATIVE)) {
1642     RuntimeCallTimerEvent();
1643   }
1644   Log::MessageBuilder msg(log_);
1645   msg << kLogEventsNames[CodeEventListener::TICK_EVENT] << kNext
1646       << reinterpret_cast<void*>(sample->pc) << kNext
1647       << timer_.Elapsed().InMicroseconds();
1648   if (sample->has_external_callback) {
1649     msg << kNext << 1 << kNext
1650         << reinterpret_cast<void*>(sample->external_callback_entry);
1651   } else {
1652     msg << kNext << 0 << kNext << reinterpret_cast<void*>(sample->tos);
1653   }
1654   msg << kNext << static_cast<int>(sample->state);
1655   if (overflow) msg << kNext << "overflow";
1656   for (unsigned i = 0; i < sample->frames_count; ++i) {
1657     msg << kNext << reinterpret_cast<void*>(sample->stack[i]);
1658   }
1659   msg.WriteToLogFile();
1660 }
1661 
ICEvent(const char * type,bool keyed,Map * map,Object * key,char old_state,char new_state,const char * modifier,const char * slow_stub_reason)1662 void Logger::ICEvent(const char* type, bool keyed, Map* map, Object* key,
1663                      char old_state, char new_state, const char* modifier,
1664                      const char* slow_stub_reason) {
1665   if (!log_->IsEnabled() || !FLAG_trace_ic) return;
1666   Log::MessageBuilder msg(log_);
1667   if (keyed) msg << "Keyed";
1668   int line;
1669   int column;
1670   Address pc = isolate_->GetAbstractPC(&line, &column);
1671   msg << type << kNext << reinterpret_cast<void*>(pc) << kNext << line << kNext
1672       << column << kNext << old_state << kNext << new_state << kNext
1673       << reinterpret_cast<void*>(map) << kNext;
1674   if (key->IsSmi()) {
1675     msg << Smi::ToInt(key);
1676   } else if (key->IsNumber()) {
1677     msg << key->Number();
1678   } else if (key->IsName()) {
1679     msg << Name::cast(key);
1680   }
1681   msg << kNext << modifier << kNext;
1682   if (slow_stub_reason != nullptr) {
1683     msg << slow_stub_reason;
1684   }
1685   msg.WriteToLogFile();
1686 }
1687 
MapEvent(const char * type,Map * from,Map * to,const char * reason,HeapObject * name_or_sfi)1688 void Logger::MapEvent(const char* type, Map* from, Map* to, const char* reason,
1689                       HeapObject* name_or_sfi) {
1690   DisallowHeapAllocation no_gc;
1691   if (!log_->IsEnabled() || !FLAG_trace_maps) return;
1692   if (to) MapDetails(to);
1693   int line = -1;
1694   int column = -1;
1695   Address pc = 0;
1696 
1697   if (!isolate_->bootstrapper()->IsActive()) {
1698     pc = isolate_->GetAbstractPC(&line, &column);
1699   }
1700   Log::MessageBuilder msg(log_);
1701   msg << "map" << kNext << type << kNext << timer_.Elapsed().InMicroseconds()
1702       << kNext << reinterpret_cast<void*>(from) << kNext
1703       << reinterpret_cast<void*>(to) << kNext << reinterpret_cast<void*>(pc)
1704       << kNext << line << kNext << column << kNext << reason << kNext;
1705 
1706   if (name_or_sfi) {
1707     if (name_or_sfi->IsName()) {
1708       msg << Name::cast(name_or_sfi);
1709     } else if (name_or_sfi->IsSharedFunctionInfo()) {
1710       SharedFunctionInfo* sfi = SharedFunctionInfo::cast(name_or_sfi);
1711       msg << sfi->DebugName();
1712 #if V8_SFI_HAS_UNIQUE_ID
1713       msg << " " << sfi->unique_id();
1714 #endif  // V8_SFI_HAS_UNIQUE_ID
1715     }
1716   }
1717   msg.WriteToLogFile();
1718 }
1719 
MapCreate(Map * map)1720 void Logger::MapCreate(Map* map) {
1721   if (!log_->IsEnabled() || !FLAG_trace_maps) return;
1722   DisallowHeapAllocation no_gc;
1723   Log::MessageBuilder msg(log_);
1724   msg << "map-create" << kNext << timer_.Elapsed().InMicroseconds() << kNext
1725       << reinterpret_cast<void*>(map);
1726   msg.WriteToLogFile();
1727 }
1728 
MapDetails(Map * map)1729 void Logger::MapDetails(Map* map) {
1730   if (!log_->IsEnabled() || !FLAG_trace_maps) return;
1731   // Disable logging Map details during bootstrapping since we use LogMaps() to
1732   // log all creating
1733   if (isolate_->bootstrapper()->IsActive()) return;
1734   DisallowHeapAllocation no_gc;
1735   Log::MessageBuilder msg(log_);
1736   msg << "map-details" << kNext << timer_.Elapsed().InMicroseconds() << kNext
1737       << reinterpret_cast<void*>(map) << kNext;
1738   if (FLAG_trace_maps_details) {
1739     std::ostringstream buffer;
1740     map->PrintMapDetails(buffer);
1741     msg << buffer.str().c_str();
1742   }
1743   msg.WriteToLogFile();
1744 }
1745 
StopProfiler()1746 void Logger::StopProfiler() {
1747   if (!log_->IsEnabled()) return;
1748   if (profiler_ != nullptr) {
1749     profiler_->Pause();
1750     is_logging_ = false;
1751     RemoveCodeEventListener(this);
1752   }
1753 }
1754 
1755 // This function can be called when Log's mutex is acquired,
1756 // either from main or Profiler's thread.
LogFailure()1757 void Logger::LogFailure() {
1758   StopProfiler();
1759 }
1760 
AddFunctionAndCode(SharedFunctionInfo * sfi,AbstractCode * code_object,Handle<SharedFunctionInfo> * sfis,Handle<AbstractCode> * code_objects,int offset)1761 static void AddFunctionAndCode(SharedFunctionInfo* sfi,
1762                                AbstractCode* code_object,
1763                                Handle<SharedFunctionInfo>* sfis,
1764                                Handle<AbstractCode>* code_objects, int offset) {
1765   if (sfis != nullptr) {
1766     sfis[offset] = Handle<SharedFunctionInfo>(sfi, sfi->GetIsolate());
1767   }
1768   if (code_objects != nullptr) {
1769     code_objects[offset] = Handle<AbstractCode>(code_object, sfi->GetIsolate());
1770   }
1771 }
1772 
EnumerateCompiledFunctions(Heap * heap,Handle<SharedFunctionInfo> * sfis,Handle<AbstractCode> * code_objects)1773 static int EnumerateCompiledFunctions(Heap* heap,
1774                                       Handle<SharedFunctionInfo>* sfis,
1775                                       Handle<AbstractCode>* code_objects) {
1776   HeapIterator iterator(heap);
1777   DisallowHeapAllocation no_gc;
1778   int compiled_funcs_count = 0;
1779 
1780   // Iterate the heap to find shared function info objects and record
1781   // the unoptimized code for them.
1782   for (HeapObject* obj = iterator.next(); obj != nullptr;
1783        obj = iterator.next()) {
1784     if (obj->IsSharedFunctionInfo()) {
1785       SharedFunctionInfo* sfi = SharedFunctionInfo::cast(obj);
1786       if (sfi->is_compiled() &&
1787           (!sfi->script()->IsScript() ||
1788            Script::cast(sfi->script())->HasValidSource())) {
1789         AddFunctionAndCode(sfi, AbstractCode::cast(sfi->abstract_code()), sfis,
1790                            code_objects, compiled_funcs_count);
1791         ++compiled_funcs_count;
1792       }
1793     } else if (obj->IsJSFunction()) {
1794       // Given that we no longer iterate over all optimized JSFunctions, we need
1795       // to take care of this here.
1796       JSFunction* function = JSFunction::cast(obj);
1797       SharedFunctionInfo* sfi = SharedFunctionInfo::cast(function->shared());
1798       Object* maybe_script = sfi->script();
1799       if (maybe_script->IsScript() &&
1800           !Script::cast(maybe_script)->HasValidSource()) {
1801         continue;
1802       }
1803       // TODO(jarin) This leaves out deoptimized code that might still be on the
1804       // stack. Also note that we will not log optimized code objects that are
1805       // only on a type feedback vector. We should make this mroe precise.
1806       if (function->IsOptimized()) {
1807         AddFunctionAndCode(sfi, AbstractCode::cast(function->code()), sfis,
1808                            code_objects, compiled_funcs_count);
1809         ++compiled_funcs_count;
1810       }
1811     }
1812   }
1813   return compiled_funcs_count;
1814 }
1815 
EnumerateWasmModuleObjects(Heap * heap,Handle<WasmModuleObject> * module_objects)1816 static int EnumerateWasmModuleObjects(
1817     Heap* heap, Handle<WasmModuleObject>* module_objects) {
1818   HeapIterator iterator(heap);
1819   DisallowHeapAllocation no_gc;
1820   int module_objects_count = 0;
1821 
1822   for (HeapObject* obj = iterator.next(); obj != nullptr;
1823        obj = iterator.next()) {
1824     if (obj->IsWasmModuleObject()) {
1825       WasmModuleObject* module = WasmModuleObject::cast(obj);
1826       if (module_objects != nullptr) {
1827         module_objects[module_objects_count] = handle(module, heap->isolate());
1828       }
1829       module_objects_count++;
1830     }
1831   }
1832   return module_objects_count;
1833 }
1834 
LogCodeObject(Object * object)1835 void Logger::LogCodeObject(Object* object) {
1836   existing_code_logger_.LogCodeObject(object);
1837 }
1838 
LogCodeObjects()1839 void Logger::LogCodeObjects() { existing_code_logger_.LogCodeObjects(); }
1840 
LogBytecodeHandler(interpreter::Bytecode bytecode,interpreter::OperandScale operand_scale,Code * code)1841 void Logger::LogBytecodeHandler(interpreter::Bytecode bytecode,
1842                                 interpreter::OperandScale operand_scale,
1843                                 Code* code) {
1844   existing_code_logger_.LogBytecodeHandler(bytecode, operand_scale, code);
1845 }
1846 
LogBytecodeHandlers()1847 void Logger::LogBytecodeHandlers() {
1848   existing_code_logger_.LogBytecodeHandlers();
1849 }
1850 
LogExistingFunction(Handle<SharedFunctionInfo> shared,Handle<AbstractCode> code)1851 void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared,
1852                                  Handle<AbstractCode> code) {
1853   existing_code_logger_.LogExistingFunction(shared, code);
1854 }
1855 
LogCompiledFunctions()1856 void Logger::LogCompiledFunctions() {
1857   existing_code_logger_.LogCompiledFunctions();
1858 }
1859 
LogAccessorCallbacks()1860 void Logger::LogAccessorCallbacks() {
1861   Heap* heap = isolate_->heap();
1862   HeapIterator iterator(heap);
1863   DisallowHeapAllocation no_gc;
1864   for (HeapObject* obj = iterator.next(); obj != nullptr;
1865        obj = iterator.next()) {
1866     if (!obj->IsAccessorInfo()) continue;
1867     AccessorInfo* ai = AccessorInfo::cast(obj);
1868     if (!ai->name()->IsName()) continue;
1869     Address getter_entry = v8::ToCData<Address>(ai->getter());
1870     Name* name = Name::cast(ai->name());
1871     if (getter_entry != 0) {
1872 #if USES_FUNCTION_DESCRIPTORS
1873       getter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(getter_entry);
1874 #endif
1875       PROFILE(isolate_, GetterCallbackEvent(name, getter_entry));
1876     }
1877     Address setter_entry = v8::ToCData<Address>(ai->setter());
1878     if (setter_entry != 0) {
1879 #if USES_FUNCTION_DESCRIPTORS
1880       setter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(setter_entry);
1881 #endif
1882       PROFILE(isolate_, SetterCallbackEvent(name, setter_entry));
1883     }
1884   }
1885 }
1886 
LogMaps()1887 void Logger::LogMaps() {
1888   Heap* heap = isolate_->heap();
1889   HeapIterator iterator(heap);
1890   DisallowHeapAllocation no_gc;
1891   for (HeapObject* obj = iterator.next(); obj != nullptr;
1892        obj = iterator.next()) {
1893     if (!obj->IsMap()) continue;
1894     MapDetails(Map::cast(obj));
1895   }
1896 }
1897 
AddIsolateIdIfNeeded(std::ostream & os,Isolate * isolate)1898 static void AddIsolateIdIfNeeded(std::ostream& os,  // NOLINT
1899                                  Isolate* isolate) {
1900   if (FLAG_logfile_per_isolate) os << "isolate-" << isolate << "-";
1901 }
1902 
1903 
PrepareLogFileName(std::ostream & os,Isolate * isolate,const char * file_name)1904 static void PrepareLogFileName(std::ostream& os,  // NOLINT
1905                                Isolate* isolate, const char* file_name) {
1906   int dir_separator_count = 0;
1907   for (const char* p = file_name; *p; p++) {
1908     if (base::OS::isDirectorySeparator(*p)) dir_separator_count++;
1909   }
1910 
1911   for (const char* p = file_name; *p; p++) {
1912     if (dir_separator_count == 0) {
1913       AddIsolateIdIfNeeded(os, isolate);
1914       dir_separator_count--;
1915     }
1916     if (*p == '%') {
1917       p++;
1918       switch (*p) {
1919         case '\0':
1920           // If there's a % at the end of the string we back up
1921           // one character so we can escape the loop properly.
1922           p--;
1923           break;
1924         case 'p':
1925           os << base::OS::GetCurrentProcessId();
1926           break;
1927         case 't':
1928           // %t expands to the current time in milliseconds.
1929           os << static_cast<int64_t>(
1930               V8::GetCurrentPlatform()->CurrentClockTimeMillis());
1931           break;
1932         case '%':
1933           // %% expands (contracts really) to %.
1934           os << '%';
1935           break;
1936         default:
1937           // All other %'s expand to themselves.
1938           os << '%' << *p;
1939           break;
1940       }
1941     } else {
1942       if (base::OS::isDirectorySeparator(*p)) dir_separator_count--;
1943       os << *p;
1944     }
1945   }
1946 }
1947 
1948 
SetUp(Isolate * isolate)1949 bool Logger::SetUp(Isolate* isolate) {
1950   // Tests and EnsureInitialize() can call this twice in a row. It's harmless.
1951   if (is_initialized_) return true;
1952   is_initialized_ = true;
1953 
1954   std::ostringstream log_file_name;
1955   std::ostringstream source_log_file_name;
1956   PrepareLogFileName(log_file_name, isolate, FLAG_logfile);
1957   log_ = new Log(this, log_file_name.str().c_str());
1958 
1959   if (FLAG_perf_basic_prof) {
1960     perf_basic_logger_ = new PerfBasicLogger(isolate);
1961     AddCodeEventListener(perf_basic_logger_);
1962   }
1963 
1964   if (FLAG_perf_prof) {
1965     perf_jit_logger_ = new PerfJitLogger(isolate);
1966     AddCodeEventListener(perf_jit_logger_);
1967   }
1968 
1969   if (FLAG_ll_prof) {
1970     ll_logger_ = new LowLevelLogger(isolate, log_file_name.str().c_str());
1971     AddCodeEventListener(ll_logger_);
1972   }
1973 
1974   ticker_ = new Ticker(isolate, FLAG_prof_sampling_interval);
1975 
1976   if (Log::InitLogAtStart()) {
1977     is_logging_ = true;
1978   }
1979 
1980   timer_.Start();
1981 
1982   if (FLAG_prof_cpp) {
1983     profiler_ = new Profiler(isolate);
1984     is_logging_ = true;
1985     profiler_->Engage();
1986   }
1987 
1988   if (is_logging_) {
1989     AddCodeEventListener(this);
1990   }
1991 
1992   return true;
1993 }
1994 
1995 
SetCodeEventHandler(uint32_t options,JitCodeEventHandler event_handler)1996 void Logger::SetCodeEventHandler(uint32_t options,
1997                                  JitCodeEventHandler event_handler) {
1998   if (jit_logger_) {
1999     RemoveCodeEventListener(jit_logger_);
2000     delete jit_logger_;
2001     jit_logger_ = nullptr;
2002   }
2003 
2004   if (event_handler) {
2005     jit_logger_ = new JitLogger(isolate_, event_handler);
2006     AddCodeEventListener(jit_logger_);
2007     if (options & kJitCodeEventEnumExisting) {
2008       HandleScope scope(isolate_);
2009       LogCodeObjects();
2010       LogCompiledFunctions();
2011     }
2012   }
2013 }
2014 
sampler()2015 sampler::Sampler* Logger::sampler() {
2016   return ticker_;
2017 }
2018 
StopProfilerThread()2019 void Logger::StopProfilerThread() {
2020   if (profiler_ != nullptr) {
2021     profiler_->Disengage();
2022     delete profiler_;
2023     profiler_ = nullptr;
2024   }
2025 }
2026 
TearDown()2027 FILE* Logger::TearDown() {
2028   if (!is_initialized_) return nullptr;
2029   is_initialized_ = false;
2030 
2031   // Stop the profiler thread before closing the file.
2032   StopProfilerThread();
2033 
2034   delete ticker_;
2035   ticker_ = nullptr;
2036 
2037   if (perf_basic_logger_) {
2038     RemoveCodeEventListener(perf_basic_logger_);
2039     delete perf_basic_logger_;
2040     perf_basic_logger_ = nullptr;
2041   }
2042 
2043   if (perf_jit_logger_) {
2044     RemoveCodeEventListener(perf_jit_logger_);
2045     delete perf_jit_logger_;
2046     perf_jit_logger_ = nullptr;
2047   }
2048 
2049   if (ll_logger_) {
2050     RemoveCodeEventListener(ll_logger_);
2051     delete ll_logger_;
2052     ll_logger_ = nullptr;
2053   }
2054 
2055   if (jit_logger_) {
2056     RemoveCodeEventListener(jit_logger_);
2057     delete jit_logger_;
2058     jit_logger_ = nullptr;
2059   }
2060 
2061   return log_->Close();
2062 }
2063 
LogCodeObject(Object * object)2064 void ExistingCodeLogger::LogCodeObject(Object* object) {
2065   AbstractCode* abstract_code = AbstractCode::cast(object);
2066   CodeEventListener::LogEventsAndTags tag = CodeEventListener::STUB_TAG;
2067   const char* description = "Unknown code from before profiling";
2068   switch (abstract_code->kind()) {
2069     case AbstractCode::INTERPRETED_FUNCTION:
2070     case AbstractCode::OPTIMIZED_FUNCTION:
2071       return;  // We log this later using LogCompiledFunctions.
2072     case AbstractCode::BYTECODE_HANDLER:
2073       return;  // We log it later by walking the dispatch table.
2074     case AbstractCode::STUB:
2075       description =
2076           CodeStub::MajorName(CodeStub::GetMajorKey(abstract_code->GetCode()));
2077       if (description == nullptr) description = "A stub from before profiling";
2078       tag = CodeEventListener::STUB_TAG;
2079       break;
2080     case AbstractCode::REGEXP:
2081       description = "Regular expression code";
2082       tag = CodeEventListener::REG_EXP_TAG;
2083       break;
2084     case AbstractCode::BUILTIN:
2085       if (Code::cast(object)->is_interpreter_trampoline_builtin() &&
2086           Code::cast(object) !=
2087               *BUILTIN_CODE(isolate_, InterpreterEntryTrampoline)) {
2088         return;
2089       }
2090       description =
2091           isolate_->builtins()->name(abstract_code->GetCode()->builtin_index());
2092       tag = CodeEventListener::BUILTIN_TAG;
2093       break;
2094     case AbstractCode::WASM_FUNCTION:
2095       description = "A Wasm function";
2096       tag = CodeEventListener::FUNCTION_TAG;
2097       break;
2098     case AbstractCode::JS_TO_WASM_FUNCTION:
2099       description = "A JavaScript to Wasm adapter";
2100       tag = CodeEventListener::STUB_TAG;
2101       break;
2102     case AbstractCode::WASM_TO_JS_FUNCTION:
2103       description = "A Wasm to JavaScript adapter";
2104       tag = CodeEventListener::STUB_TAG;
2105       break;
2106     case AbstractCode::WASM_INTERPRETER_ENTRY:
2107       description = "A Wasm to Interpreter adapter";
2108       tag = CodeEventListener::STUB_TAG;
2109       break;
2110     case AbstractCode::C_WASM_ENTRY:
2111       description = "A C to Wasm entry stub";
2112       tag = CodeEventListener::STUB_TAG;
2113       break;
2114     case AbstractCode::NUMBER_OF_KINDS:
2115       UNIMPLEMENTED();
2116   }
2117   CALL_CODE_EVENT_HANDLER(CodeCreateEvent(tag, abstract_code, description))
2118 }
2119 
LogCodeObjects()2120 void ExistingCodeLogger::LogCodeObjects() {
2121   Heap* heap = isolate_->heap();
2122   HeapIterator iterator(heap);
2123   DisallowHeapAllocation no_gc;
2124   for (HeapObject* obj = iterator.next(); obj != nullptr;
2125        obj = iterator.next()) {
2126     if (obj->IsCode()) LogCodeObject(obj);
2127     if (obj->IsBytecodeArray()) LogCodeObject(obj);
2128   }
2129 }
2130 
LogCompiledFunctions()2131 void ExistingCodeLogger::LogCompiledFunctions() {
2132   Heap* heap = isolate_->heap();
2133   HandleScope scope(isolate_);
2134   const int compiled_funcs_count =
2135       EnumerateCompiledFunctions(heap, nullptr, nullptr);
2136   ScopedVector<Handle<SharedFunctionInfo>> sfis(compiled_funcs_count);
2137   ScopedVector<Handle<AbstractCode>> code_objects(compiled_funcs_count);
2138   EnumerateCompiledFunctions(heap, sfis.start(), code_objects.start());
2139 
2140   // During iteration, there can be heap allocation due to
2141   // GetScriptLineNumber call.
2142   for (int i = 0; i < compiled_funcs_count; ++i) {
2143     if (sfis[i]->function_data()->IsInterpreterData()) {
2144       LogExistingFunction(
2145           sfis[i],
2146           Handle<AbstractCode>(
2147               AbstractCode::cast(sfis[i]->InterpreterTrampoline()), isolate_),
2148           CodeEventListener::INTERPRETED_FUNCTION_TAG);
2149     }
2150     if (code_objects[i].is_identical_to(BUILTIN_CODE(isolate_, CompileLazy)))
2151       continue;
2152     LogExistingFunction(sfis[i], code_objects[i]);
2153   }
2154 
2155   const int wasm_module_objects_count =
2156       EnumerateWasmModuleObjects(heap, nullptr);
2157   std::unique_ptr<Handle<WasmModuleObject>[]> module_objects(
2158       new Handle<WasmModuleObject>[wasm_module_objects_count]);
2159   EnumerateWasmModuleObjects(heap, module_objects.get());
2160   for (int i = 0; i < wasm_module_objects_count; ++i) {
2161     module_objects[i]->native_module()->LogWasmCodes(isolate_);
2162   }
2163 }
2164 
LogBytecodeHandler(interpreter::Bytecode bytecode,interpreter::OperandScale operand_scale,Code * code)2165 void ExistingCodeLogger::LogBytecodeHandler(
2166     interpreter::Bytecode bytecode, interpreter::OperandScale operand_scale,
2167     Code* code) {
2168   std::string bytecode_name =
2169       interpreter::Bytecodes::ToString(bytecode, operand_scale);
2170   CALL_CODE_EVENT_HANDLER(
2171       CodeCreateEvent(CodeEventListener::BYTECODE_HANDLER_TAG,
2172                       AbstractCode::cast(code), bytecode_name.c_str()))
2173 }
2174 
LogBytecodeHandlers()2175 void ExistingCodeLogger::LogBytecodeHandlers() {
2176   const interpreter::OperandScale kOperandScales[] = {
2177 #define VALUE(Name, _) interpreter::OperandScale::k##Name,
2178       OPERAND_SCALE_LIST(VALUE)
2179 #undef VALUE
2180   };
2181 
2182   const int last_index = static_cast<int>(interpreter::Bytecode::kLast);
2183   interpreter::Interpreter* interpreter = isolate_->interpreter();
2184   for (auto operand_scale : kOperandScales) {
2185     for (int index = 0; index <= last_index; ++index) {
2186       interpreter::Bytecode bytecode = interpreter::Bytecodes::FromByte(index);
2187       if (interpreter::Bytecodes::BytecodeHasHandler(bytecode, operand_scale)) {
2188         Code* code = interpreter->GetBytecodeHandler(bytecode, operand_scale);
2189         if (isolate_->heap()->IsDeserializeLazyHandler(code)) continue;
2190         LogBytecodeHandler(bytecode, operand_scale, code);
2191       }
2192     }
2193   }
2194 }
2195 
LogExistingFunction(Handle<SharedFunctionInfo> shared,Handle<AbstractCode> code,CodeEventListener::LogEventsAndTags tag)2196 void ExistingCodeLogger::LogExistingFunction(
2197     Handle<SharedFunctionInfo> shared, Handle<AbstractCode> code,
2198     CodeEventListener::LogEventsAndTags tag) {
2199   if (shared->script()->IsScript()) {
2200     Handle<Script> script(Script::cast(shared->script()), isolate_);
2201     int line_num = Script::GetLineNumber(script, shared->StartPosition()) + 1;
2202     int column_num =
2203         Script::GetColumnNumber(script, shared->StartPosition()) + 1;
2204     if (script->name()->IsString()) {
2205       Handle<String> script_name(String::cast(script->name()), isolate_);
2206       if (line_num > 0) {
2207         CALL_CODE_EVENT_HANDLER(
2208             CodeCreateEvent(Logger::ToNativeByScript(tag, *script), *code,
2209                             *shared, *script_name, line_num, column_num))
2210       } else {
2211         // Can't distinguish eval and script here, so always use Script.
2212         CALL_CODE_EVENT_HANDLER(CodeCreateEvent(
2213             Logger::ToNativeByScript(CodeEventListener::SCRIPT_TAG, *script),
2214             *code, *shared, *script_name))
2215       }
2216     } else {
2217       CALL_CODE_EVENT_HANDLER(CodeCreateEvent(
2218           Logger::ToNativeByScript(tag, *script), *code, *shared,
2219           ReadOnlyRoots(isolate_).empty_string(), line_num, column_num))
2220     }
2221   } else if (shared->IsApiFunction()) {
2222     // API function.
2223     FunctionTemplateInfo* fun_data = shared->get_api_func_data();
2224     Object* raw_call_data = fun_data->call_code();
2225     if (!raw_call_data->IsUndefined(isolate_)) {
2226       CallHandlerInfo* call_data = CallHandlerInfo::cast(raw_call_data);
2227       Object* callback_obj = call_data->callback();
2228       Address entry_point = v8::ToCData<Address>(callback_obj);
2229 #if USES_FUNCTION_DESCRIPTORS
2230       entry_point = *FUNCTION_ENTRYPOINT_ADDRESS(entry_point);
2231 #endif
2232       CALL_CODE_EVENT_HANDLER(CallbackEvent(shared->DebugName(), entry_point))
2233     }
2234   }
2235 }
2236 
2237 #undef CALL_CODE_EVENT_HANDLER
2238 
2239 }  // namespace internal
2240 }  // namespace v8
2241