log.h 18 KB
Newer Older
1
// Copyright 2012 the V8 project authors. All rights reserved.
2 3
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
4

5 6
#ifndef V8_LOGGING_LOG_H_
#define V8_LOGGING_LOG_H_
7

8
#include <memory>
9
#include <set>
10 11
#include <string>

12
#include "include/v8-profiler.h"
13
#include "src/base/platform/elapsed-timer.h"
14
#include "src/logging/code-events.h"
15
#include "src/objects/objects.h"
16

17
namespace v8 {
18

19 20 21 22
namespace sampler {
class Sampler;
}

23
namespace internal {
24

25 26
struct TickSample;

27 28 29 30 31 32 33 34 35 36
// Logger is used for collecting logging information from V8 during
// execution. The result is dumped to a file.
//
// Available command line flags:
//
//  --log
// Minimal logging (no API, code, or GC sample events), default is off.
//
// --log-all
// Log all events to the file, default is off.  This is the same as combining
Hannes Payer's avatar
Hannes Payer committed
37
// --log-api, --log-code, and --log-regexp.
38 39 40 41 42 43 44 45
//
// --log-api
// Log API events to the logfile, default is off.  --log-api implies --log.
//
// --log-code
// Log code (create, move, and delete) events to the logfile, default is off.
// --log-code implies --log.
//
46
// --log-regexp
47
// Log creation and use of regular expressions, Default is off.
48 49
// --log-regexp implies --log.
//
50 51 52 53 54 55
// --logfile <filename>
// Specify the name of the logfile, default is "v8.log".
//
// --prof
// Collect statistical profiling information (ticks), default is off.  The
// tick profiler requires code events, so --prof implies --log-code.
56 57 58 59
//
// --prof-sampling-interval <microseconds>
// The interval between --prof samples, default is 1000 microseconds (5000 on
// Android).
60 61

// Forward declarations.
62
class CodeEventListener;
63
class Isolate;
64
class JitLogger;
65
class Log;
66 67 68
class LowLevelLogger;
class PerfBasicLogger;
class PerfJitLogger;
69
class Profiler;
70
class SourcePosition;
71
class Ticker;
72

73
#undef LOG
74 75
#define LOG(isolate, Call)                  \
  do {                                      \
76
    auto&& logger = (isolate)->logger();    \
77
    if (logger->is_logging()) logger->Call; \
78
  } while (false)
79

80 81
#define LOG_CODE_EVENT(isolate, Call)                        \
  do {                                                       \
82
    auto&& logger = (isolate)->logger();                     \
83
    if (logger->is_listening_to_code_events()) logger->Call; \
84 85
  } while (false)

86 87 88 89 90 91 92 93 94 95
class ExistingCodeLogger {
 public:
  explicit ExistingCodeLogger(Isolate* isolate,
                              CodeEventListener* listener = nullptr)
      : isolate_(isolate), listener_(listener) {}

  void LogCodeObjects();

  void LogCompiledFunctions();
  void LogExistingFunction(Handle<SharedFunctionInfo> shared,
96 97 98
                           Handle<AbstractCode> code,
                           CodeEventListener::LogEventsAndTags tag =
                               CodeEventListener::LAZY_COMPILE_TAG);
99
  void LogCodeObject(Object object);
100 101 102 103 104 105

 private:
  Isolate* isolate_;
  CodeEventListener* listener_;
};

106 107
enum class LogSeparator;

108
class Logger : public CodeEventListener {
109
 public:
110
  enum StartEnd { START = 0, END = 1, STAMP = 2 };
111

112 113 114 115
  enum class ScriptEventType {
    kReserveId,
    kCreate,
    kDeserialize,
116 117
    kBackgroundCompile,
    kStreamingCompile
118 119
  };

120
  explicit Logger(Isolate* isolate);
121
  ~Logger() override;
122

123
  // The separator is used to write an unescaped "," into the log.
124
  static const LogSeparator kNext;
125

126
  // Acquires resources for logging if the right flags are set.
127
  bool SetUp(Isolate* isolate);
128

129
  // Sets the current code event handler.
130
  void SetCodeEventHandler(uint32_t options, JitCodeEventHandler event_handler);
131

132
  sampler::Sampler* sampler();
133

134
  V8_EXPORT_PRIVATE void StopProfilerThread();
135

136
  // Frees resources acquired in SetUp.
137 138
  // When a temporary file is used for the log, returns its stream descriptor,
  // leaving the file open.
139
  V8_EXPORT_PRIVATE FILE* TearDown();
140 141

  // Emits an event with a string value -> (name, value).
142
  V8_EXPORT_PRIVATE void StringEvent(const char* name, const char* value);
143 144

  // Emits an event with an int value -> (name, value).
145
  void IntPtrTEvent(const char* name, intptr_t value);
146 147

  // Emits an event with an handle value -> (name, location).
148
  void HandleEvent(const char* name, Address* location);
149 150

  // Emits memory management events for C allocated structures.
151 152 153
  void NewEvent(const char* name, void* object, size_t size);
  void DeleteEvent(const char* name, void* object);

154 155 156 157
  // Emits an event with a tag, and some resource usage information.
  // -> (name, tag, <rusage information>).
  // Currently, the resource usage information is a process time stamp
  // and a real time timestamp.
158
  void ResourceEvent(const char* name, const char* tag);
159 160 161

  // Emits an event that an undefined property was read from an
  // object.
162
  void SuspectReadEvent(Name name, Object obj);
163

164 165
  // ==== Events logged by --log-function-events ====
  void FunctionEvent(const char* reason, int script_id, double time_delta_ms,
166 167
                     int start_position, int end_position,
                     String function_name);
168 169
  void FunctionEvent(const char* reason, int script_id, double time_delta_ms,
                     int start_position, int end_position,
170
                     const char* function_name = nullptr,
171
                     size_t function_name_length = 0);
172

173
  void CompilationCacheEvent(const char* action, const char* cache_type,
174
                             SharedFunctionInfo sfi);
175
  void ScriptEvent(ScriptEventType type, int script_id);
176
  void ScriptDetails(Script script);
177

178
  // ==== Events logged by --log-api. ====
179
  void ApiSecurityCheck();
180
  void ApiNamedPropertyAccess(const char* tag, JSObject holder, Object name);
181
  void ApiIndexedPropertyAccess(const char* tag, JSObject holder,
182
                                uint32_t index);
183
  void ApiObjectAccess(const char* tag, JSObject obj);
184
  void ApiEntryCall(const char* name);
185 186

  // ==== Events logged by --log-code. ====
187 188
  V8_EXPORT_PRIVATE void AddCodeEventListener(CodeEventListener* listener);
  V8_EXPORT_PRIVATE void RemoveCodeEventListener(CodeEventListener* listener);
189

190 191 192 193 194 195 196 197 198 199 200 201
  // CodeEventListener implementation.
  void CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
                       const char* name) override;
  void CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
                       Handle<Name> name) override;
  void CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
                       Handle<SharedFunctionInfo> shared,
                       Handle<Name> script_name) override;
  void CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
                       Handle<SharedFunctionInfo> shared,
                       Handle<Name> script_name, int line, int column) override;
  void CodeCreateEvent(LogEventsAndTags tag, const wasm::WasmCode* code,
202
                       wasm::WasmName name) override;
203 204 205 206 207 208

  void CallbackEvent(Handle<Name> name, Address entry_point) override;
  void GetterCallbackEvent(Handle<Name> name, Address entry_point) override;
  void SetterCallbackEvent(Handle<Name> name, Address entry_point) override;
  void RegExpCodeCreateEvent(Handle<AbstractCode> code,
                             Handle<String> source) override;
209
  void CodeMoveEvent(AbstractCode from, AbstractCode to) override;
210 211 212 213 214 215
  void SharedFunctionInfoMoveEvent(Address from, Address to) override;
  void NativeContextMoveEvent(Address from, Address to) override {}
  void CodeMovingGCEvent() override;
  void CodeDisableOptEvent(Handle<AbstractCode> code,
                           Handle<SharedFunctionInfo> shared) override;
  void CodeDeoptEvent(Handle<Code> code, DeoptimizeKind kind, Address pc,
216
                      int fp_to_sp_delta, bool reuse_code) override;
217 218 219 220 221 222
  void CodeDependencyChangeEvent(Handle<Code> code,
                                 Handle<SharedFunctionInfo> sfi,
                                 const char* reason) override;

  void ProcessDeoptEvent(Handle<Code> code, SourcePosition position,
                         const char* kind, const char* reason);
223

224
  // Emits a code line info record event.
225
  void CodeLinePosInfoRecordEvent(Address code_start,
226
                                  ByteArray source_position_table);
227 228
  void CodeLinePosInfoRecordEvent(Address code_start,
                                  Vector<const byte> source_position_table);
229

230
  void CodeNameEvent(Address addr, int pos, const char* code_name);
231

232 233 234
  void 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);
235

236
  void MapEvent(const char* type, Handle<Map> from, Handle<Map> to,
237
                const char* reason = nullptr,
238
                Handle<HeapObject> name_or_sfi = Handle<HeapObject>());
239 240
  void MapCreate(Map map);
  void MapDetails(Map map);
241

242 243
  void SharedLibraryEvent(const std::string& library_path, uintptr_t start,
                          uintptr_t end, intptr_t aslr_slide);
244

245
  void CurrentTimeEvent();
246

247
  V8_EXPORT_PRIVATE void TimerEvent(StartEnd se, const char* name);
248

249 250 251 252
  void BasicBlockCounterEvent(const char* name, int block_id, uint32_t count);

  void BuiltinHashEvent(const char* name, int hash);

253 254
  static void EnterExternal(Isolate* isolate);
  static void LeaveExternal(Isolate* isolate);
255

256 257
  static void DefaultEventLoggerSentinel(const char* name, int event) {}

258 259
  V8_INLINE static void CallEventLogger(Isolate* isolate, const char* name,
                                        StartEnd se, bool expose_to_api);
260

261
  V8_EXPORT_PRIVATE bool is_logging();
262

263
  bool is_listening_to_code_events() override {
264
    return is_logging() || jit_logger_ != nullptr;
265 266
  }

267
  void LogExistingFunction(Handle<SharedFunctionInfo> shared,
268
                           Handle<AbstractCode> code);
269
  // Logs all compiled functions found in the heap.
270
  V8_EXPORT_PRIVATE void LogCompiledFunctions();
271
  // Logs all accessor callbacks found in the heap.
272
  V8_EXPORT_PRIVATE void LogAccessorCallbacks();
273
  // Used for logging stubs found in the snapshot.
274
  V8_EXPORT_PRIVATE void LogCodeObjects();
275 276
  // Logs all Maps found on the heap.
  void LogAllMaps();
277

278
  // Converts tag to a corresponding NATIVE_... if the script is native.
279
  V8_INLINE static CodeEventListener::LogEventsAndTags ToNativeByScript(
280
      CodeEventListener::LogEventsAndTags, Script);
281

282
  // Used for logging stubs found in the snapshot.
283
  void LogCodeObject(Object code_object);
284

285
 private:
286
  // Emits the profiler's first message.
287
  void ProfilerBeginEvent();
288

289
  // Emits callback event messages.
290
  void CallbackEventInternal(const char* prefix, Handle<Name> name,
291
                             Address entry_point);
292

293
  // Internal configurable move event.
294 295
  void MoveEventInternal(CodeEventListener::LogEventsAndTags event,
                         Address from, Address to);
296

297
  // Helper method. It resets name_buffer_ and add tag name into it.
298
  void InitNameBuffer(CodeEventListener::LogEventsAndTags tag);
299

300
  // Emits a profiler tick event. Used by the profiler thread.
301
  void TickEvent(TickSample* sample, bool overflow);
302
  void RuntimeCallTimerEvent();
303

304
  // Logs a StringEvent regardless of whether FLAG_log is true.
305
  void UncheckedStringEvent(const char* name, const char* value);
306

307
  // Logs an IntPtrTEvent regardless of whether FLAG_log is true.
308
  void UncheckedIntPtrTEvent(const char* name, intptr_t value);
309

310 311
  // Logs a scripts sources. Keeps track of all logged scripts to ensure that
  // each script is logged only once.
312
  bool EnsureLogScriptSource(Script script);
313

314 315
  Isolate* isolate_;

316
  // The sampler used by the profiler and the sliding state window.
317
  std::unique_ptr<Ticker> ticker_;
318 319 320 321

  // When the statistical profile is active, profiler_
  // points to a Profiler, that handles collection
  // of samples.
322
  std::unique_ptr<Profiler> profiler_;
323

324
  // Internal implementation classes with access to private members.
325
  friend class Profiler;
326

327
  bool is_logging_;
328
  std::unique_ptr<Log> log_;
329
#if V8_OS_LINUX
330
  std::unique_ptr<PerfBasicLogger> perf_basic_logger_;
331
  std::unique_ptr<PerfJitLogger> perf_jit_logger_;
332
#endif
333 334
  std::unique_ptr<LowLevelLogger> ll_logger_;
  std::unique_ptr<JitLogger> jit_logger_;
335 336
  std::set<int> logged_source_code_;
  uint32_t next_source_info_id_ = 0;
337

338
  // Guards against multiple calls to TearDown() that can happen in some tests.
339
  // 'true' between SetUp() and TearDown().
340 341
  bool is_initialized_;

342 343
  ExistingCodeLogger existing_code_logger_;

344
  base::ElapsedTimer timer_;
345 346
};

347 348 349 350 351 352 353 354 355
#define TIMER_EVENTS_LIST(V)     \
  V(RecompileSynchronous, true)  \
  V(RecompileConcurrent, true)   \
  V(CompileIgnition, true)       \
  V(CompileFullCode, true)       \
  V(OptimizeCode, true)          \
  V(CompileCode, true)           \
  V(CompileCodeBackground, true) \
  V(DeoptimizeCode, true)        \
356
  V(Execute, true)
357

358 359 360 361 362 363 364
#define V(TimerName, expose)                          \
  class TimerEvent##TimerName : public AllStatic {    \
   public:                                            \
    static const char* name(void* unused = nullptr) { \
      return "V8." #TimerName;                        \
    }                                                 \
    static bool expose_to_api() { return expose; }    \
365 366 367 368 369 370 371 372 373 374 375 376 377 378
  };
TIMER_EVENTS_LIST(V)
#undef V

template <class TimerEvent>
class TimerEventScope {
 public:
  explicit TimerEventScope(Isolate* isolate) : isolate_(isolate) {
    LogTimerEvent(Logger::START);
  }

  ~TimerEventScope() { LogTimerEvent(Logger::END); }

 private:
379
  void LogTimerEvent(Logger::StartEnd se);
380 381 382
  Isolate* isolate_;
};

383
// Abstract
384
class V8_EXPORT_PRIVATE CodeEventLogger : public CodeEventListener {
385
 public:
386
  explicit CodeEventLogger(Isolate* isolate);
387 388
  ~CodeEventLogger() override;

389 390 391 392 393 394 395 396 397 398
  void CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
                       const char* name) override;
  void CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
                       Handle<Name> name) override;
  void CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
                       Handle<SharedFunctionInfo> shared,
                       Handle<Name> script_name) override;
  void CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
                       Handle<SharedFunctionInfo> shared,
                       Handle<Name> script_name, int line, int column) override;
399
  void CodeCreateEvent(LogEventsAndTags tag, const wasm::WasmCode* code,
400 401
                       wasm::WasmName name) override;

402 403 404 405 406
  void RegExpCodeCreateEvent(Handle<AbstractCode> code,
                             Handle<String> source) override;
  void CallbackEvent(Handle<Name> name, Address entry_point) override {}
  void GetterCallbackEvent(Handle<Name> name, Address entry_point) override {}
  void SetterCallbackEvent(Handle<Name> name, Address entry_point) override {}
407
  void SharedFunctionInfoMoveEvent(Address from, Address to) override {}
408
  void NativeContextMoveEvent(Address from, Address to) override {}
409
  void CodeMovingGCEvent() override {}
410
  void CodeDeoptEvent(Handle<Code> code, DeoptimizeKind kind, Address pc,
411
                      int fp_to_sp_delta, bool reuse_code) override {}
412 413 414
  void CodeDependencyChangeEvent(Handle<Code> code,
                                 Handle<SharedFunctionInfo> sfi,
                                 const char* reason) override {}
415

416 417 418
 protected:
  Isolate* isolate_;

419 420 421
 private:
  class NameBuffer;

422 423
  virtual void LogRecordedBuffer(Handle<AbstractCode> code,
                                 MaybeHandle<SharedFunctionInfo> maybe_shared,
424
                                 const char* name, int length) = 0;
425
  virtual void LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
426
                                 int length) = 0;
427

428
  std::unique_ptr<NameBuffer> name_buffer_;
429 430
};

431
struct CodeEvent {
432
  Isolate* isolate_;
433 434 435 436 437 438 439 440
  uintptr_t code_start_address;
  size_t code_size;
  Handle<String> function_name;
  Handle<String> script_name;
  int script_line;
  int script_column;
  CodeEventType code_type;
  const char* comment;
441
  uintptr_t previous_code_start_address;
442 443 444 445 446 447 448
};

class ExternalCodeEventListener : public CodeEventListener {
 public:
  explicit ExternalCodeEventListener(Isolate* isolate);
  ~ExternalCodeEventListener() override;

449
  void CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
450
                       const char* comment) override;
451 452 453 454 455 456 457 458
  void CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
                       Handle<Name> name) override;
  void CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
                       Handle<SharedFunctionInfo> shared,
                       Handle<Name> name) override;
  void CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
                       Handle<SharedFunctionInfo> shared, Handle<Name> source,
                       int line, int column) override;
459 460 461
  void CodeCreateEvent(LogEventsAndTags tag, const wasm::WasmCode* code,
                       wasm::WasmName name) override;

462 463 464 465 466
  void RegExpCodeCreateEvent(Handle<AbstractCode> code,
                             Handle<String> source) override;
  void CallbackEvent(Handle<Name> name, Address entry_point) override {}
  void GetterCallbackEvent(Handle<Name> name, Address entry_point) override {}
  void SetterCallbackEvent(Handle<Name> name, Address entry_point) override {}
467
  void SharedFunctionInfoMoveEvent(Address from, Address to) override {}
468
  void NativeContextMoveEvent(Address from, Address to) override {}
469
  void CodeMoveEvent(AbstractCode from, AbstractCode to) override;
470 471
  void CodeDisableOptEvent(Handle<AbstractCode> code,
                           Handle<SharedFunctionInfo> shared) override {}
472
  void CodeMovingGCEvent() override {}
473
  void CodeDeoptEvent(Handle<Code> code, DeoptimizeKind kind, Address pc,
474
                      int fp_to_sp_delta, bool reuse_code) override {}
475 476 477
  void CodeDependencyChangeEvent(Handle<Code> code,
                                 Handle<SharedFunctionInfo> sfi,
                                 const char* reason) override {}
478

479
  void StartListening(v8::CodeEventHandler* code_event_handler);
480 481 482 483 484 485 486 487 488 489 490
  void StopListening();

  bool is_listening_to_code_events() override { return true; }

 private:
  void LogExistingCode();

  bool is_listening_;
  Isolate* isolate_;
  v8::CodeEventHandler* code_event_handler_;
};
491

492 493
}  // namespace internal
}  // namespace v8
494

495
#endif  // V8_LOGGING_LOG_H_