log.h 17.1 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 Ticker;
71

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

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

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

  void LogCodeObjects();

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

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

105 106
enum class LogSeparator;

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

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

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

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

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

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

131
  sampler::Sampler* sampler();
132

133
  V8_EXPORT_PRIVATE void StopProfilerThread();
134

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

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

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

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

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

153 154 155 156
  // 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.
157
  void ResourceEvent(const char* name, const char* tag);
158 159 160

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

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

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

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

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

189 190 191 192 193 194 195 196 197 198 199 200
  // 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,
201
                       wasm::WasmName name) override;
202 203 204 205 206 207

  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;
208
  void CodeMoveEvent(AbstractCode from, AbstractCode to) override;
209 210 211 212 213 214 215 216
  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,
                      int fp_to_sp_delta) override;

217
  // Emits a code line info record event.
218
  void CodeLinePosInfoRecordEvent(Address code_start,
219
                                  ByteArray source_position_table);
220 221
  void CodeLinePosInfoRecordEvent(Address code_start,
                                  Vector<const byte> source_position_table);
222

223
  void CodeNameEvent(Address addr, int pos, const char* code_name);
224

225 226 227
  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);
228

229
  void MapEvent(const char* type, Handle<Map> from, Handle<Map> to,
230
                const char* reason = nullptr,
231
                Handle<HeapObject> name_or_sfi = Handle<HeapObject>());
232 233
  void MapCreate(Map map);
  void MapDetails(Map map);
234

235 236
  void SharedLibraryEvent(const std::string& library_path, uintptr_t start,
                          uintptr_t end, intptr_t aslr_slide);
237

238
  void CurrentTimeEvent();
239

240
  V8_EXPORT_PRIVATE void TimerEvent(StartEnd se, const char* name);
241

242 243
  static void EnterExternal(Isolate* isolate);
  static void LeaveExternal(Isolate* isolate);
244

245 246
  static void DefaultEventLoggerSentinel(const char* name, int event) {}

247 248
  V8_INLINE static void CallEventLogger(Isolate* isolate, const char* name,
                                        StartEnd se, bool expose_to_api);
249

250
  V8_EXPORT_PRIVATE bool is_logging();
251

252
  bool is_listening_to_code_events() override {
253
    return is_logging() || jit_logger_ != nullptr;
254 255
  }

256
  void LogExistingFunction(Handle<SharedFunctionInfo> shared,
257
                           Handle<AbstractCode> code);
258
  // Logs all compiled functions found in the heap.
259
  V8_EXPORT_PRIVATE void LogCompiledFunctions();
260
  // Logs all accessor callbacks found in the heap.
261
  V8_EXPORT_PRIVATE void LogAccessorCallbacks();
262
  // Used for logging stubs found in the snapshot.
263
  V8_EXPORT_PRIVATE void LogCodeObjects();
264 265
  // Logs all Maps found on the heap.
  void LogAllMaps();
266

267
  // Converts tag to a corresponding NATIVE_... if the script is native.
268
  V8_INLINE static CodeEventListener::LogEventsAndTags ToNativeByScript(
269
      CodeEventListener::LogEventsAndTags, Script);
270

271
  // Used for logging stubs found in the snapshot.
272
  void LogCodeObject(Object code_object);
273

274
 private:
275
  // Emits the profiler's first message.
276
  void ProfilerBeginEvent();
277

278
  // Emits callback event messages.
279
  void CallbackEventInternal(const char* prefix, Handle<Name> name,
280
                             Address entry_point);
281

282
  // Internal configurable move event.
283 284
  void MoveEventInternal(CodeEventListener::LogEventsAndTags event,
                         Address from, Address to);
285

286
  // Helper method. It resets name_buffer_ and add tag name into it.
287
  void InitNameBuffer(CodeEventListener::LogEventsAndTags tag);
288

289
  // Emits a profiler tick event. Used by the profiler thread.
290
  void TickEvent(TickSample* sample, bool overflow);
291
  void RuntimeCallTimerEvent();
292

293
  // Logs a StringEvent regardless of whether FLAG_log is true.
294
  void UncheckedStringEvent(const char* name, const char* value);
295

296
  // Logs an IntPtrTEvent regardless of whether FLAG_log is true.
297
  void UncheckedIntPtrTEvent(const char* name, intptr_t value);
298

299 300
  // Logs a scripts sources. Keeps track of all logged scripts to ensure that
  // each script is logged only once.
301
  bool EnsureLogScriptSource(Script script);
302

303 304
  Isolate* isolate_;

305
  // The sampler used by the profiler and the sliding state window.
306
  std::unique_ptr<Ticker> ticker_;
307 308 309 310

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

313
  // Internal implementation classes with access to private members.
314
  friend class Profiler;
315

316
  bool is_logging_;
317
  std::unique_ptr<Log> log_;
318
#if V8_OS_LINUX
319
  std::unique_ptr<PerfBasicLogger> perf_basic_logger_;
320
  std::unique_ptr<PerfJitLogger> perf_jit_logger_;
321
#endif
322 323
  std::unique_ptr<LowLevelLogger> ll_logger_;
  std::unique_ptr<JitLogger> jit_logger_;
324 325
  std::set<int> logged_source_code_;
  uint32_t next_source_info_id_ = 0;
326

327
  // Guards against multiple calls to TearDown() that can happen in some tests.
328
  // 'true' between SetUp() and TearDown().
329 330
  bool is_initialized_;

331 332
  ExistingCodeLogger existing_code_logger_;

333
  base::ElapsedTimer timer_;
334 335
};

336 337 338 339 340 341 342 343 344
#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)        \
345
  V(Execute, true)
346

347 348 349 350 351 352 353
#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; }    \
354 355 356 357 358 359 360 361 362 363 364 365 366 367
  };
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:
368
  void LogTimerEvent(Logger::StartEnd se);
369 370 371
  Isolate* isolate_;
};

372
// Abstract
373
class V8_EXPORT_PRIVATE CodeEventLogger : public CodeEventListener {
374
 public:
375
  explicit CodeEventLogger(Isolate* isolate);
376 377
  ~CodeEventLogger() override;

378 379 380 381 382 383 384 385 386 387
  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;
388
  void CodeCreateEvent(LogEventsAndTags tag, const wasm::WasmCode* code,
389 390
                       wasm::WasmName name) override;

391 392 393 394 395
  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 {}
396
  void SharedFunctionInfoMoveEvent(Address from, Address to) override {}
397
  void NativeContextMoveEvent(Address from, Address to) override {}
398
  void CodeMovingGCEvent() override {}
399
  void CodeDeoptEvent(Handle<Code> code, DeoptimizeKind kind, Address pc,
400
                      int fp_to_sp_delta) override {}
401

402 403 404
 protected:
  Isolate* isolate_;

405 406 407
 private:
  class NameBuffer;

408 409
  virtual void LogRecordedBuffer(Handle<AbstractCode> code,
                                 MaybeHandle<SharedFunctionInfo> maybe_shared,
410
                                 const char* name, int length) = 0;
411
  virtual void LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
412
                                 int length) = 0;
413

414
  std::unique_ptr<NameBuffer> name_buffer_;
415 416
};

417
struct CodeEvent {
418
  Isolate* isolate_;
419 420 421 422 423 424 425 426
  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;
427
  uintptr_t previous_code_start_address;
428 429 430 431 432 433 434
};

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

435
  void CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
436
                       const char* comment) override;
437 438 439 440 441 442 443 444
  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;
445 446 447
  void CodeCreateEvent(LogEventsAndTags tag, const wasm::WasmCode* code,
                       wasm::WasmName name) override;

448 449 450 451 452
  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 {}
453
  void SharedFunctionInfoMoveEvent(Address from, Address to) override {}
454
  void NativeContextMoveEvent(Address from, Address to) override {}
455
  void CodeMoveEvent(AbstractCode from, AbstractCode to) override;
456 457
  void CodeDisableOptEvent(Handle<AbstractCode> code,
                           Handle<SharedFunctionInfo> shared) override {}
458
  void CodeMovingGCEvent() override {}
459
  void CodeDeoptEvent(Handle<Code> code, DeoptimizeKind kind, Address pc,
460 461
                      int fp_to_sp_delta) override {}

462
  void StartListening(v8::CodeEventHandler* code_event_handler);
463 464 465 466 467 468 469 470 471 472 473
  void StopListening();

  bool is_listening_to_code_events() override { return true; }

 private:
  void LogExistingCode();

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

475 476
}  // namespace internal
}  // namespace v8
477

478
#endif  // V8_LOGGING_LOG_H_