xref: /third_party/node/deps/v8/src/logging/log.cc (revision 1cb0ef41)
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
63namespace v8 {
64namespace internal {
65
66#define DECLARE_EVENT(ignore1, name) #name,
67static const char* kLogEventsNames[CodeEventListener::NUMBER_OF_LOG_EVENTS] = {
68    LOG_EVENTS_AND_TAGS_LIST(DECLARE_EVENT)};
69#undef DECLARE_EVENT
70
71static 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
95static 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
113static 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
123class CodeEventLogger::NameBuffer {
124 public:
125  NameBuffer() { Reset(); }
126
127  void Reset() { utf8_pos_ = 0; }
128
129  void Init(LogEventsAndTags tag) {
130    Reset();
131    AppendBytes(kLogEventsNames[tag]);
132    AppendByte(':');
133  }
134
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
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
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
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
172  void AppendByte(char c) {
173    if (utf8_pos_ >= kUtf8BufferSize) return;
174    utf8_buffer_[utf8_pos_++] = c;
175  }
176
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
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
197  const char* get() { return utf8_buffer_; }
198  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
208CodeEventLogger::CodeEventLogger(Isolate* isolate)
209    : isolate_(isolate), name_buffer_(std::make_unique<NameBuffer>()) {}
210
211CodeEventLogger::~CodeEventLogger() = default;
212
213void 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
223void 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
233void 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
245void 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
268void 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
289void 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
300class PerfBasicLogger : public CodeEventLogger {
301 public:
302  explicit PerfBasicLogger(Isolate* isolate);
303  ~PerfBasicLogger() override;
304
305  void CodeMoveEvent(AbstractCode from, AbstractCode to) override {}
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
327const char PerfBasicLogger::kFilenameFormatString[] = "/tmp/perf-%d.map";
328// Extra space for the PID in the filename
329const int PerfBasicLogger::kFilenameBufferPadding = 16;
330
331PerfBasicLogger::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
345PerfBasicLogger::~PerfBasicLogger() {
346  base::Fclose(perf_output_handle_);
347  perf_output_handle_ = nullptr;
348}
349
350void 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
363void 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
376void 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
385ExternalCodeEventListener::ExternalCodeEventListener(Isolate* isolate)
386    : is_listening_(false), isolate_(isolate), code_event_handler_(nullptr) {}
387
388ExternalCodeEventListener::~ExternalCodeEventListener() {
389  if (is_listening_) {
390    StopListening();
391  }
392}
393
394void ExternalCodeEventListener::LogExistingCode() {
395  HandleScope scope(isolate_);
396  ExistingCodeLogger logger(isolate_, this);
397  logger.LogCodeObjects();
398  logger.LogCompiledFunctions();
399}
400
401void 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
413void ExternalCodeEventListener::StopListening() {
414  if (!is_listening_) {
415    return;
416  }
417
418  isolate_->code_event_dispatcher()->RemoveListener(this);
419  is_listening_ = false;
420}
421
422void 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
439void 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
459void 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
479void 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
504void 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
511void 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
527void 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.
545class 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;
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>
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
599const char LowLevelLogger::kLogExt[] = ".ll";
600
601LowLevelLogger::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
615LowLevelLogger::~LowLevelLogger() {
616  base::Fclose(ll_output_handle_);
617  ll_output_handle_ = nullptr;
618}
619
620void 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
647void 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
661void 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
674void 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
681void 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
687void LowLevelLogger::CodeMovingGCEvent() {
688  const char tag = kCodeMovingGCTag;
689
690  LogWriteBytes(&tag, sizeof(tag));
691}
692
693class JitLogger : public CodeEventLogger {
694 public:
695  JitLogger(Isolate* isolate, JitCodeEventHandler code_event_handler);
696
697  void CodeMoveEvent(AbstractCode from, AbstractCode to) override;
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
722JitLogger::JitLogger(Isolate* isolate, JitCodeEventHandler code_event_handler)
723    : CodeEventLogger(isolate), code_event_handler_(code_event_handler) {}
724
725void 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
747void 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
797void 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
812void 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
828void* 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
838void 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.
854class SamplingThread : public base::Thread {
855 public:
856  static const int kSamplingThreadStackSize = 64 * KB;
857
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) {}
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//
881class 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.
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.
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.
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//
934class Ticker : public sampler::Sampler {
935 public:
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
942  ~Ticker() override {
943    if (IsActive()) Stop();
944  }
945
946  void SetProfiler(Profiler* profiler) {
947    DCHECK_NULL(profiler_);
948    profiler_ = profiler;
949    if (!IsActive()) Start();
950    sampling_thread_->StartSynchronously();
951  }
952
953  void ClearProfiler() {
954    profiler_ = nullptr;
955    if (IsActive()) Stop();
956    sampling_thread_->Join();
957  }
958
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//
981Profiler::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
991void 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
1011void 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
1026void 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
1043Logger::Logger(Isolate* isolate)
1044    : isolate_(isolate),
1045      is_logging_(false),
1046      is_initialized_(false),
1047      existing_code_logger_(isolate) {}
1048
1049Logger::~Logger() = default;
1050
1051const LogSeparator Logger::kNext = LogSeparator::kSeparator;
1052
1053int64_t Logger::Time() {
1054  if (FLAG_verify_predictable) {
1055    return isolate_->heap()->MonotonicallyIncreasingTimeInMs() * 1000;
1056  }
1057  return timer_.Elapsed().InMicroseconds();
1058}
1059
1060void Logger::AddCodeEventListener(CodeEventListener* listener) {
1061  bool result = isolate_->code_event_dispatcher()->AddListener(listener);
1062  CHECK(result);
1063}
1064
1065void Logger::RemoveCodeEventListener(CodeEventListener* listener) {
1066  isolate_->code_event_dispatcher()->RemoveListener(listener);
1067}
1068
1069void Logger::ProfilerBeginEvent() {
1070  MSG_BUILDER();
1071  msg << "profiler" << kNext << "begin" << kNext << FLAG_prof_sampling_interval;
1072  msg.WriteToLogFile();
1073}
1074
1075void Logger::StringEvent(const char* name, const char* value) {
1076  if (FLAG_log) UncheckedStringEvent(name, value);
1077}
1078
1079void Logger::UncheckedStringEvent(const char* name, const char* value) {
1080  MSG_BUILDER();
1081  msg << name << kNext << value;
1082  msg.WriteToLogFile();
1083}
1084
1085void 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
1093void 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
1104void Logger::SharedLibraryEnd() {
1105  if (!FLAG_prof_cpp) return;
1106  MSG_BUILDER();
1107  msg << "shared-library-end";
1108  msg.WriteToLogFile();
1109}
1110
1111void Logger::CurrentTimeEvent() {
1112  DCHECK(FLAG_log_internal_timer_events);
1113  MSG_BUILDER();
1114  msg << "current-time" << kNext << Time();
1115  msg.WriteToLogFile();
1116}
1117
1118void 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
1134void 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
1143void 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
1151bool 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);
1161TIMER_EVENTS_LIST(V)
1162#undef V
1163
1164void 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
1172void 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
1179namespace {
1180
1181void 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
1192void 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
1223void 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
1287void 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
1309void 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
1322void 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
1336void 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
1356void 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.
1384void 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
1403void 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
1427void 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
1438void Logger::CallbackEvent(Handle<Name> name, Address entry_point) {
1439  CallbackEventInternal("", name, entry_point);
1440}
1441
1442void Logger::GetterCallbackEvent(Handle<Name> name, Address entry_point) {
1443  CallbackEventInternal("get ", name, entry_point);
1444}
1445
1446void Logger::SetterCallbackEvent(Handle<Name> name, Address entry_point) {
1447  CallbackEventInternal("set ", name, entry_point);
1448}
1449
1450void 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
1460void 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
1466void 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
1471void Logger::CodeMovingGCEvent() {
1472  if (!is_listening_to_code_events()) return;
1473  if (!FLAG_ll_prof) return;
1474  base::OS::SignalCodeMovingGC();
1475}
1476
1477void 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
1488void 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
1510void 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
1518void 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
1526namespace {
1527
1528void 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
1548void 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
1557void 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
1565void 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
1574void 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
1583namespace {
1584void 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
1599void 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
1610void 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
1624void 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
1639void 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
1664void 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
1682bool 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
1713void 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
1724void 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
1747void 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
1776void 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
1808void 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
1816void 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
1830static std::vector<std::pair<Handle<SharedFunctionInfo>, Handle<AbstractCode>>>
1831EnumerateCompiledFunctions(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
1883void Logger::LogCodeObjects() { existing_code_logger_.LogCodeObjects(); }
1884
1885void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared,
1886                                 Handle<AbstractCode> code) {
1887  existing_code_logger_.LogExistingFunction(shared, code);
1888}
1889
1890void Logger::LogCompiledFunctions() {
1891  existing_code_logger_.LogCompiledFunctions();
1892}
1893
1894void Logger::LogBuiltins() { existing_code_logger_.LogBuiltins(); }
1895
1896void 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
1924void 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
1936static void AddIsolateIdIfNeeded(std::ostream& os, Isolate* isolate) {
1937  if (!FLAG_logfile_per_isolate) return;
1938  os << "isolate-" << isolate << "-" << base::OS::GetCurrentProcessId() << "-";
1939}
1940
1941static 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
1985bool 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
2051void 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
2059void 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
2081sampler::Sampler* Logger::sampler() { return ticker_.get(); }
2082std::string Logger::file_name() const { return log_.get()->file_name(); }
2083
2084void Logger::StopProfilerThread() {
2085  if (profiler_ != nullptr) {
2086    profiler_->Disengage();
2087    profiler_.reset();
2088  }
2089}
2090
2091FILE* 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
2127void 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
2137void 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
2199void 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
2210void 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
2220void 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
2263void 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