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