log.h 21.1 KB
Newer Older
1
// Copyright 2012 the V8 project authors. All rights reserved.
2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30
// Redistribution and use in source and binary forms, with or without
// modification, are permitted provided that the following conditions are
// met:
//
//     * Redistributions of source code must retain the above copyright
//       notice, this list of conditions and the following disclaimer.
//     * Redistributions in binary form must reproduce the above
//       copyright notice, this list of conditions and the following
//       disclaimer in the documentation and/or other materials provided
//       with the distribution.
//     * Neither the name of Google Inc. nor the names of its
//       contributors may be used to endorse or promote products derived
//       from this software without specific prior written permission.
//
// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.

#ifndef V8_LOG_H_
#define V8_LOG_H_

31
#include "allocation.h"
32
#include "objects.h"
33
#include "platform.h"
34
#include "platform/elapsed-timer.h"
35

36 37
namespace v8 {
namespace internal {
38 39 40 41 42 43 44 45 46 47 48

// 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
49
// --log-api, --log-code, --log-gc, and --log-regexp.
50 51 52 53 54 55 56 57 58 59 60 61
//
// --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.
//
// --log-gc
// Log GC heap samples after each GC that can be processed by hp2ps, default
// is off.  --log-gc implies --log.
//
62
// --log-regexp
63
// Log creation and use of regular expressions, Default is off.
64 65
// --log-regexp implies --log.
//
66 67 68 69 70 71 72 73
// --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.

// Forward declarations.
74
class CodeEventListener;
75 76 77 78 79
class CompilationInfo;
class CpuProfiler;
class Isolate;
class Log;
class PositionsRecorder;
80 81
class Profiler;
class Semaphore;
82
class Ticker;
83
struct TickSample;
84 85

#undef LOG
86 87 88 89 90 91
#define LOG(isolate, Call)                          \
  do {                                              \
    v8::internal::Logger* logger =                  \
        (isolate)->logger();                        \
    if (logger->is_logging())                       \
      logger->Call;                                 \
92
  } while (false)
93

94 95 96 97 98 99 100 101 102
#define LOG_CODE_EVENT(isolate, Call)               \
  do {                                              \
    v8::internal::Logger* logger =                  \
        (isolate)->logger();                        \
    if (logger->is_logging_code_events())           \
      logger->Call;                                 \
  } while (false)


danno@chromium.org's avatar
danno@chromium.org committed
103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133
#define LOG_EVENTS_AND_TAGS_LIST(V)                                     \
  V(CODE_CREATION_EVENT,            "code-creation")                    \
  V(CODE_MOVE_EVENT,                "code-move")                        \
  V(CODE_DELETE_EVENT,              "code-delete")                      \
  V(CODE_MOVING_GC,                 "code-moving-gc")                   \
  V(SHARED_FUNC_MOVE_EVENT,         "sfi-move")                         \
  V(SNAPSHOT_POSITION_EVENT,        "snapshot-pos")                     \
  V(SNAPSHOT_CODE_NAME_EVENT,       "snapshot-code-name")               \
  V(TICK_EVENT,                     "tick")                             \
  V(REPEAT_META_EVENT,              "repeat")                           \
  V(BUILTIN_TAG,                    "Builtin")                          \
  V(CALL_DEBUG_BREAK_TAG,           "CallDebugBreak")                   \
  V(CALL_DEBUG_PREPARE_STEP_IN_TAG, "CallDebugPrepareStepIn")           \
  V(CALL_IC_TAG,                    "CallIC")                           \
  V(CALL_INITIALIZE_TAG,            "CallInitialize")                   \
  V(CALL_MEGAMORPHIC_TAG,           "CallMegamorphic")                  \
  V(CALL_MISS_TAG,                  "CallMiss")                         \
  V(CALL_NORMAL_TAG,                "CallNormal")                       \
  V(CALL_PRE_MONOMORPHIC_TAG,       "CallPreMonomorphic")               \
  V(KEYED_CALL_DEBUG_BREAK_TAG,     "KeyedCallDebugBreak")              \
  V(KEYED_CALL_DEBUG_PREPARE_STEP_IN_TAG,                               \
    "KeyedCallDebugPrepareStepIn")                                      \
  V(KEYED_CALL_IC_TAG,              "KeyedCallIC")                      \
  V(KEYED_CALL_INITIALIZE_TAG,      "KeyedCallInitialize")              \
  V(KEYED_CALL_MEGAMORPHIC_TAG,     "KeyedCallMegamorphic")             \
  V(KEYED_CALL_MISS_TAG,            "KeyedCallMiss")                    \
  V(KEYED_CALL_NORMAL_TAG,          "KeyedCallNormal")                  \
  V(KEYED_CALL_PRE_MONOMORPHIC_TAG, "KeyedCallPreMonomorphic")          \
  V(CALLBACK_TAG,                   "Callback")                         \
  V(EVAL_TAG,                       "Eval")                             \
  V(FUNCTION_TAG,                   "Function")                         \
134
  V(HANDLER_TAG,                    "Handler")                          \
danno@chromium.org's avatar
danno@chromium.org committed
135
  V(KEYED_LOAD_IC_TAG,              "KeyedLoadIC")                      \
136
  V(KEYED_LOAD_POLYMORPHIC_IC_TAG,  "KeyedLoadPolymorphicIC")           \
danno@chromium.org's avatar
danno@chromium.org committed
137 138
  V(KEYED_EXTERNAL_ARRAY_LOAD_IC_TAG, "KeyedExternalArrayLoadIC")       \
  V(KEYED_STORE_IC_TAG,             "KeyedStoreIC")                     \
139
  V(KEYED_STORE_POLYMORPHIC_IC_TAG, "KeyedStorePolymorphicIC")          \
danno@chromium.org's avatar
danno@chromium.org committed
140 141 142
  V(KEYED_EXTERNAL_ARRAY_STORE_IC_TAG, "KeyedExternalArrayStoreIC")     \
  V(LAZY_COMPILE_TAG,               "LazyCompile")                      \
  V(LOAD_IC_TAG,                    "LoadIC")                           \
143
  V(LOAD_POLYMORPHIC_IC_TAG,        "LoadPolymorphicIC")                \
danno@chromium.org's avatar
danno@chromium.org committed
144 145 146
  V(REG_EXP_TAG,                    "RegExp")                           \
  V(SCRIPT_TAG,                     "Script")                           \
  V(STORE_IC_TAG,                   "StoreIC")                          \
147
  V(STORE_POLYMORPHIC_IC_TAG,       "StorePolymorphicIC")               \
danno@chromium.org's avatar
danno@chromium.org committed
148 149 150
  V(STUB_TAG,                       "Stub")                             \
  V(NATIVE_FUNCTION_TAG,            "Function")                         \
  V(NATIVE_LAZY_COMPILE_TAG,        "LazyCompile")                      \
151
  V(NATIVE_SCRIPT_TAG,              "Script")
mikhail.naganov@gmail.com's avatar
mikhail.naganov@gmail.com committed
152 153 154
// Note that 'NATIVE_' cases for functions and scripts are mapped onto
// original tags when writing to the log.

155

156
class JitLogger;
157
class LowLevelLogger;
158 159
class Sampler;

160 161
class Logger {
 public:
162
#define DECLARE_ENUM(enum_item, ignore) enum_item,
163 164 165 166 167 168
  enum LogEventsAndTags {
    LOG_EVENTS_AND_TAGS_LIST(DECLARE_ENUM)
    NUMBER_OF_LOG_EVENTS
  };
#undef DECLARE_ENUM

169
  // Acquires resources for logging if the right flags are set.
170
  bool SetUp(Isolate* isolate);
171

172 173 174 175
  // Sets the current code event handler.
  void SetCodeEventHandler(uint32_t options,
                           JitCodeEventHandler event_handler);

176
  Sampler* sampler();
177

178
  // Frees resources acquired in SetUp.
179 180 181
  // When a temporary file is used for the log, returns its stream descriptor,
  // leaving the file open.
  FILE* TearDown();
182 183

  // Emits an event with a string value -> (name, value).
184
  void StringEvent(const char* name, const char* value);
185 186

  // Emits an event with an int value -> (name, value).
187 188
  void IntEvent(const char* name, int value);
  void IntPtrTEvent(const char* name, intptr_t value);
189 190

  // Emits an event with an handle value -> (name, location).
191
  void HandleEvent(const char* name, Object** location);
192 193

  // Emits memory management events for C allocated structures.
194 195 196 197 198 199 200
  void NewEvent(const char* name, void* object, size_t size);
  void DeleteEvent(const char* name, void* object);

  // Static versions of the above, operate on current isolate's logger.
  // Used in TRACK_MEMORY(TypeName) defined in globals.h
  static void NewEventStatic(const char* name, void* object, size_t size);
  static void DeleteEventStatic(const char* name, void* object);
201 202 203 204 205

  // 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.
206
  void ResourceEvent(const char* name, const char* tag);
207 208 209

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

212 213
  // Emits an event when a message is put on or read from a debugging queue.
  // DebugTag lets us put a call-site specific label on the event.
214 215
  void DebugTag(const char* call_site_tag);
  void DebugEvent(const char* event_type, Vector<uint16_t> parameter);
216

217 218

  // ==== Events logged by --log-api. ====
219 220 221 222 223 224 225 226
  void ApiNamedSecurityCheck(Object* key);
  void ApiIndexedSecurityCheck(uint32_t index);
  void ApiNamedPropertyAccess(const char* tag, JSObject* holder, Object* name);
  void ApiIndexedPropertyAccess(const char* tag,
                                JSObject* holder,
                                uint32_t index);
  void ApiObjectAccess(const char* tag, JSObject* obj);
  void ApiEntryCall(const char* name);
227 228 229


  // ==== Events logged by --log-code. ====
230 231 232 233 234
  void addCodeEventListener(CodeEventListener* listener);
  void removeCodeEventListener(CodeEventListener* listener);
  bool hasCodeEventListener(CodeEventListener* listener);


235
  // Emits a code event for a callback function.
236 237 238
  void CallbackEvent(Name* name, Address entry_point);
  void GetterCallbackEvent(Name* name, Address entry_point);
  void SetterCallbackEvent(Name* name, Address entry_point);
239
  // Emits a code create event.
240 241 242
  void CodeCreateEvent(LogEventsAndTags tag,
                       Code* code, const char* source);
  void CodeCreateEvent(LogEventsAndTags tag,
243
                       Code* code, Name* name);
244 245 246
  void CodeCreateEvent(LogEventsAndTags tag,
                       Code* code,
                       SharedFunctionInfo* shared,
247
                       CompilationInfo* info,
248
                       Name* name);
249 250 251
  void CodeCreateEvent(LogEventsAndTags tag,
                       Code* code,
                       SharedFunctionInfo* shared,
252
                       CompilationInfo* info,
253
                       Name* source, int line, int column);
254 255
  void CodeCreateEvent(LogEventsAndTags tag, Code* code, int args_count);
  void CodeMovingGCEvent();
256
  // Emits a code create event for a RegExp.
257
  void RegExpCodeCreateEvent(Code* code, String* source);
258
  // Emits a code move event.
259
  void CodeMoveEvent(Address from, Address to);
260
  // Emits a code delete event.
261
  void CodeDeleteEvent(Address from);
262 263 264 265 266 267 268 269 270 271 272 273 274
  // Emits a code line info add event with Postion type.
  void CodeLinePosInfoAddPositionEvent(void* jit_handler_data,
                                       int pc_offset,
                                       int position);
  // Emits a code line info add event with StatementPostion type.
  void CodeLinePosInfoAddStatementPositionEvent(void* jit_handler_data,
                                                int pc_offset,
                                                int position);
  // Emits a code line info start to record event
  void CodeStartLinePosInfoRecordEvent(PositionsRecorder* pos_recorder);
  // Emits a code line info finish record event.
  // It's the callee's responsibility to dispose the parameter jit_handler_data.
  void CodeEndLinePosInfoRecordEvent(Code* code, void* jit_handler_data);
275

276
  void SharedFunctionInfoMoveEvent(Address from, Address to);
277

278
  void CodeNameEvent(Address addr, int pos, const char* code_name);
279
  void SnapshotPositionEvent(Address addr, int pos);
280

281 282
  // ==== Events logged by --log-gc. ====
  // Heap sampling events: start, end, and individual types.
283 284 285 286 287 288
  void HeapSampleBeginEvent(const char* space, const char* kind);
  void HeapSampleEndEvent(const char* space, const char* kind);
  void HeapSampleItemEvent(const char* type, int number, int bytes);
  void HeapSampleJSConstructorEvent(const char* constructor,
                                    int number, int bytes);
  void HeapSampleJSRetainersEvent(const char* constructor,
289
                                         const char* event);
290 291 292 293 294 295 296 297 298 299 300
  void HeapSampleJSProducerEvent(const char* constructor,
                                 Address* stack);
  void HeapSampleStats(const char* space, const char* kind,
                       intptr_t capacity, intptr_t used);

  void SharedLibraryEvent(const char* library_path,
                          uintptr_t start,
                          uintptr_t end);
  void SharedLibraryEvent(const wchar_t* library_path,
                          uintptr_t start,
                          uintptr_t end);
301 302

  // ==== Events logged by --log-timer-events. ====
303 304
  enum StartEnd { START, END };

305 306
  void CodeDeoptEvent(Code* code);

307
  void TimerEvent(StartEnd se, const char* name);
308

309 310
  static void EnterExternal(Isolate* isolate);
  static void LeaveExternal(Isolate* isolate);
311

312 313
  class TimerEventScope {
   public:
314
    TimerEventScope(Isolate* isolate, const char* name)
315 316
        : isolate_(isolate), name_(name) {
      if (FLAG_log_internal_timer_events) LogTimerEvent(START);
317 318 319
    }

    ~TimerEventScope() {
320
      if (FLAG_log_internal_timer_events) LogTimerEvent(END);
321 322
    }

323
    void LogTimerEvent(StartEnd se);
324

325
    static const char* v8_recompile_synchronous;
326
    static const char* v8_recompile_concurrent;
327 328
    static const char* v8_compile_full_code;
    static const char* v8_execute;
329
    static const char* v8_external;
330 331

   private:
332
    Isolate* isolate_;
333 334
    const char* name_;
  };
335

336 337 338
  // ==== Events logged by --log-regexp ====
  // Regexp compilation and execution events.

339
  void RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache);
340

341
  // Log an event reported from generated code
yurys@chromium.org's avatar
yurys@chromium.org committed
342
  void LogRuntime(Vector<const char> format, JSArray* args);
343

344
  bool is_logging() {
345
    return is_logging_;
346
  }
347

348
  bool is_logging_code_events() {
349
    return is_logging() || jit_logger_ != NULL;
350 351
  }

352 353 354
  // Stop collection of profiling data.
  // When data collection is paused, CPU Tick events are discarded.
  void StopProfiler();
355

356 357
  void LogExistingFunction(Handle<SharedFunctionInfo> shared,
                           Handle<Code> code);
358
  // Logs all compiled functions found in the heap.
359
  void LogCompiledFunctions();
360
  // Logs all accessor callbacks found in the heap.
361
  void LogAccessorCallbacks();
362
  // Used for logging stubs found in the snapshot.
363
  void LogCodeObjects();
364

365 366 367
  // Converts tag to a corresponding NATIVE_... if the script is native.
  INLINE(static LogEventsAndTags ToNativeByScript(LogEventsAndTags, Script*));

368
  // Profiler's sampling interval (in milliseconds).
369 370 371 372 373
#if defined(ANDROID)
  // Phones and tablets have processors that are much slower than desktop
  // and laptop computers for which current heuristics are tuned.
  static const int kSamplingIntervalMs = 5;
#else
374
  static const int kSamplingIntervalMs = 1;
375
#endif
376

377 378 379
  // Callback from Log, stops profiling in case of insufficient resources.
  void LogFailure();

380
 private:
381
  explicit Logger(Isolate* isolate);
382
  ~Logger();
383

384
  // Emits the profiler's first message.
385
  void ProfilerBeginEvent();
386

387
  // Emits callback event messages.
388
  void CallbackEventInternal(const char* prefix,
389
                             Name* name,
390
                             Address entry_point);
391

392
  // Internal configurable move event.
393
  void MoveEventInternal(LogEventsAndTags event, Address from, Address to);
394

395
  // Emits the source code of a regexp. Used by regexp events.
396
  void LogRegExpSource(Handle<JSRegExp> regexp);
397

398
  // Used for logging stubs found in the snapshot.
399
  void LogCodeObject(Object* code_object);
400

401 402 403
  // Helper method. It resets name_buffer_ and add tag name into it.
  void InitNameBuffer(LogEventsAndTags tag);

404
  // Emits a profiler tick event. Used by the profiler thread.
405
  void TickEvent(TickSample* sample, bool overflow);
406

407
  void ApiEvent(const char* name, ...);
408

409
  // Logs a StringEvent regardless of whether FLAG_log is true.
410
  void UncheckedStringEvent(const char* name, const char* value);
411

412
  // Logs an IntEvent regardless of whether FLAG_log is true.
413 414
  void UncheckedIntEvent(const char* name, int value);
  void UncheckedIntPtrTEvent(const char* name, intptr_t value);
415

416 417
  Isolate* isolate_;

418
  // The sampler used by the profiler and the sliding state window.
419
  Ticker* ticker_;
420 421 422 423

  // When the statistical profile is active, profiler_
  // points to a Profiler, that handles collection
  // of samples.
424
  Profiler* profiler_;
425

426 427
  // An array of log events names.
  const char* const* log_events_;
428 429 430 431

  // Internal implementation classes with access to
  // private members.
  friend class EventLog;
432
  friend class Isolate;
433 434
  friend class TimeLog;
  friend class Profiler;
435
  template <StateTag Tag> friend class VMState;
436
  friend class LoggerTestHelper;
437

438
  bool is_logging_;
439
  Log* log_;
440
  LowLevelLogger* ll_logger_;
441
  JitLogger* jit_logger_;
442
  List<CodeEventListener*> listeners_;
443

444
  // Guards against multiple calls to TearDown() that can happen in some tests.
445
  // 'true' between SetUp() and TearDown().
446 447
  bool is_initialized_;

448
  ElapsedTimer timer_;
449

450
  friend class CpuProfiler;
451 452 453
};


454 455 456 457 458 459 460 461 462 463 464 465 466 467 468 469 470 471 472 473
class CodeEventListener {
 public:
  virtual ~CodeEventListener() {}

  virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
                               Code* code,
                               const char* comment) = 0;
  virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
                               Code* code,
                               Name* name) = 0;
  virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
                               Code* code,
                               SharedFunctionInfo* shared,
                               CompilationInfo* info,
                               Name* name) = 0;
  virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
                               Code* code,
                               SharedFunctionInfo* shared,
                               CompilationInfo* info,
                               Name* source,
474
                               int line, int column) = 0;
475 476 477 478 479 480 481 482 483 484 485 486 487 488 489 490 491 492 493 494 495 496 497 498 499 500 501 502 503 504 505 506 507 508 509 510 511 512
  virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
                               Code* code,
                               int args_count) = 0;
  virtual void CallbackEvent(Name* name, Address entry_point) = 0;
  virtual void GetterCallbackEvent(Name* name, Address entry_point) = 0;
  virtual void SetterCallbackEvent(Name* name, Address entry_point) = 0;
  virtual void RegExpCodeCreateEvent(Code* code, String* source) = 0;
  virtual void CodeMoveEvent(Address from, Address to) = 0;
  virtual void CodeDeleteEvent(Address from) = 0;
  virtual void SharedFunctionInfoMoveEvent(Address from, Address to) = 0;
  virtual void CodeMovingGCEvent() = 0;
};


class CodeEventLogger : public CodeEventListener {
 public:
  CodeEventLogger();
  virtual ~CodeEventLogger();

  virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
                               Code* code,
                               const char* comment);
  virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
                               Code* code,
                               Name* name);
  virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
                               Code* code,
                               int args_count);
  virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
                               Code* code,
                               SharedFunctionInfo* shared,
                               CompilationInfo* info,
                               Name* name);
  virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
                               Code* code,
                               SharedFunctionInfo* shared,
                               CompilationInfo* info,
                               Name* source,
513
                               int line, int column);
514 515 516 517 518 519 520 521 522 523 524 525 526 527 528 529 530 531 532 533
  virtual void RegExpCodeCreateEvent(Code* code, String* source);

  virtual void CallbackEvent(Name* name, Address entry_point) { }
  virtual void GetterCallbackEvent(Name* name, Address entry_point) { }
  virtual void SetterCallbackEvent(Name* name, Address entry_point) { }
  virtual void SharedFunctionInfoMoveEvent(Address from, Address to) { }
  virtual void CodeMovingGCEvent() { }

 private:
  class NameBuffer;

  virtual void LogRecordedBuffer(Code* code,
                                 SharedFunctionInfo* shared,
                                 const char* name,
                                 int length) = 0;

  NameBuffer* name_buffer_;
};


534 535
} }  // namespace v8::internal

536

537
#endif  // V8_LOG_H_