log.h revision 3ef787dbeca8a5fb1086949cda830dccee07bfbd 
1// Copyright 2012 the V8 project authors. All rights reserved.
2// Redistribution and use in source and binary forms, with or without
3// modification, are permitted provided that the following conditions are
4// met:
5//
6//     * Redistributions of source code must retain the above copyright
7//       notice, this list of conditions and the following disclaimer.
8//     * Redistributions in binary form must reproduce the above
9//       copyright notice, this list of conditions and the following
10//       disclaimer in the documentation and/or other materials provided
11//       with the distribution.
12//     * Neither the name of Google Inc. nor the names of its
13//       contributors may be used to endorse or promote products derived
14//       from this software without specific prior written permission.
15//
16// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
17// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
18// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
19// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
20// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
21// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
22// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
23// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
24// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
25// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
26// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
27
28#ifndef V8_LOG_H_
29#define V8_LOG_H_
30
31#include "allocation.h"
32#include "objects.h"
33#include "platform.h"
34#include "log-utils.h"
35
36namespace v8 {
37namespace internal {
38
39// Logger is used for collecting logging information from V8 during
40// execution. The result is dumped to a file.
41//
42// Available command line flags:
43//
44//  --log
45// Minimal logging (no API, code, or GC sample events), default is off.
46//
47// --log-all
48// 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// --log-api
52// Log API events to the logfile, default is off.  --log-api implies --log.
53//
54// --log-code
55// Log code (create, move, and delete) events to the logfile, default is off.
56// --log-code implies --log.
57//
58// --log-gc
59// Log GC heap samples after each GC that can be processed by hp2ps, default
60// is off.  --log-gc implies --log.
61//
62// --log-regexp
63// Log creation and use of regular expressions, Default is off.
64// --log-regexp implies --log.
65//
66// --logfile <filename>
67// Specify the name of the logfile, default is "v8.log".
68//
69// --prof
70// Collect statistical profiling information (ticks), default is off.  The
71// tick profiler requires code events, so --prof implies --log-code.
72
73// Forward declarations.
74class LogMessageBuilder;
75class Profiler;
76class Semaphore;
77class SlidingStateWindow;
78class Ticker;
79
80#undef LOG
81#define LOG(isolate, Call)                          \
82  do {                                              \
83    v8::internal::Logger* logger =                  \
84        (isolate)->logger();                        \
85    if (logger->is_logging())                       \
86      logger->Call;                                 \
87  } while (false)
88
89#define LOG_EVENTS_AND_TAGS_LIST(V)                                     \
90  V(CODE_CREATION_EVENT,            "code-creation")                    \
91  V(CODE_MOVE_EVENT,                "code-move")                        \
92  V(CODE_DELETE_EVENT,              "code-delete")                      \
93  V(CODE_MOVING_GC,                 "code-moving-gc")                   \
94  V(SHARED_FUNC_MOVE_EVENT,         "sfi-move")                         \
95  V(SNAPSHOT_POSITION_EVENT,        "snapshot-pos")                     \
96  V(SNAPSHOT_CODE_NAME_EVENT,       "snapshot-code-name")               \
97  V(TICK_EVENT,                     "tick")                             \
98  V(REPEAT_META_EVENT,              "repeat")                           \
99  V(BUILTIN_TAG,                    "Builtin")                          \
100  V(CALL_DEBUG_BREAK_TAG,           "CallDebugBreak")                   \
101  V(CALL_DEBUG_PREPARE_STEP_IN_TAG, "CallDebugPrepareStepIn")           \
102  V(CALL_IC_TAG,                    "CallIC")                           \
103  V(CALL_INITIALIZE_TAG,            "CallInitialize")                   \
104  V(CALL_MEGAMORPHIC_TAG,           "CallMegamorphic")                  \
105  V(CALL_MISS_TAG,                  "CallMiss")                         \
106  V(CALL_NORMAL_TAG,                "CallNormal")                       \
107  V(CALL_PRE_MONOMORPHIC_TAG,       "CallPreMonomorphic")               \
108  V(KEYED_CALL_DEBUG_BREAK_TAG,     "KeyedCallDebugBreak")              \
109  V(KEYED_CALL_DEBUG_PREPARE_STEP_IN_TAG,                               \
110    "KeyedCallDebugPrepareStepIn")                                      \
111  V(KEYED_CALL_IC_TAG,              "KeyedCallIC")                      \
112  V(KEYED_CALL_INITIALIZE_TAG,      "KeyedCallInitialize")              \
113  V(KEYED_CALL_MEGAMORPHIC_TAG,     "KeyedCallMegamorphic")             \
114  V(KEYED_CALL_MISS_TAG,            "KeyedCallMiss")                    \
115  V(KEYED_CALL_NORMAL_TAG,          "KeyedCallNormal")                  \
116  V(KEYED_CALL_PRE_MONOMORPHIC_TAG, "KeyedCallPreMonomorphic")          \
117  V(CALLBACK_TAG,                   "Callback")                         \
118  V(EVAL_TAG,                       "Eval")                             \
119  V(FUNCTION_TAG,                   "Function")                         \
120  V(KEYED_LOAD_IC_TAG,              "KeyedLoadIC")                      \
121  V(KEYED_LOAD_MEGAMORPHIC_IC_TAG,  "KeyedLoadMegamorphicIC")           \
122  V(KEYED_EXTERNAL_ARRAY_LOAD_IC_TAG, "KeyedExternalArrayLoadIC")       \
123  V(KEYED_STORE_IC_TAG,             "KeyedStoreIC")                     \
124  V(KEYED_STORE_MEGAMORPHIC_IC_TAG, "KeyedStoreMegamorphicIC")          \
125  V(KEYED_EXTERNAL_ARRAY_STORE_IC_TAG, "KeyedExternalArrayStoreIC")     \
126  V(LAZY_COMPILE_TAG,               "LazyCompile")                      \
127  V(LOAD_IC_TAG,                    "LoadIC")                           \
128  V(REG_EXP_TAG,                    "RegExp")                           \
129  V(SCRIPT_TAG,                     "Script")                           \
130  V(STORE_IC_TAG,                   "StoreIC")                          \
131  V(STUB_TAG,                       "Stub")                             \
132  V(NATIVE_FUNCTION_TAG,            "Function")                         \
133  V(NATIVE_LAZY_COMPILE_TAG,        "LazyCompile")                      \
134  V(NATIVE_SCRIPT_TAG,              "Script")
135// Note that 'NATIVE_' cases for functions and scripts are mapped onto
136// original tags when writing to the log.
137
138
139class Sampler;
140
141
142class Logger {
143 public:
144#define DECLARE_ENUM(enum_item, ignore) enum_item,
145  enum LogEventsAndTags {
146    LOG_EVENTS_AND_TAGS_LIST(DECLARE_ENUM)
147    NUMBER_OF_LOG_EVENTS
148  };
149#undef DECLARE_ENUM
150
151  // Acquires resources for logging if the right flags are set.
152  bool SetUp();
153
154  void EnsureTickerStarted();
155  void EnsureTickerStopped();
156
157  Sampler* sampler();
158
159  // Frees resources acquired in SetUp.
160  // When a temporary file is used for the log, returns its stream descriptor,
161  // leaving the file open.
162  FILE* TearDown();
163
164  // Enable the computation of a sliding window of states.
165  void EnableSlidingStateWindow();
166
167  // Emits an event with a string value -> (name, value).
168  void StringEvent(const char* name, const char* value);
169
170  // Emits an event with an int value -> (name, value).
171  void IntEvent(const char* name, int value);
172  void IntPtrTEvent(const char* name, intptr_t value);
173
174  // Emits an event with an handle value -> (name, location).
175  void HandleEvent(const char* name, Object** location);
176
177  // Emits memory management events for C allocated structures.
178  void NewEvent(const char* name, void* object, size_t size);
179  void DeleteEvent(const char* name, void* object);
180
181  // Static versions of the above, operate on current isolate's logger.
182  // Used in TRACK_MEMORY(TypeName) defined in globals.h
183  static void NewEventStatic(const char* name, void* object, size_t size);
184  static void DeleteEventStatic(const char* name, void* object);
185
186  // Emits an event with a tag, and some resource usage information.
187  // -> (name, tag, <rusage information>).
188  // Currently, the resource usage information is a process time stamp
189  // and a real time timestamp.
190  void ResourceEvent(const char* name, const char* tag);
191
192  // Emits an event that an undefined property was read from an
193  // object.
194  void SuspectReadEvent(String* name, Object* obj);
195
196  // Emits an event when a message is put on or read from a debugging queue.
197  // DebugTag lets us put a call-site specific label on the event.
198  void DebugTag(const char* call_site_tag);
199  void DebugEvent(const char* event_type, Vector<uint16_t> parameter);
200
201
202  // ==== Events logged by --log-api. ====
203  void ApiNamedSecurityCheck(Object* key);
204  void ApiIndexedSecurityCheck(uint32_t index);
205  void ApiNamedPropertyAccess(const char* tag, JSObject* holder, Object* name);
206  void ApiIndexedPropertyAccess(const char* tag,
207                                JSObject* holder,
208                                uint32_t index);
209  void ApiObjectAccess(const char* tag, JSObject* obj);
210  void ApiEntryCall(const char* name);
211
212
213  // ==== Events logged by --log-code. ====
214  // Emits a code event for a callback function.
215  void CallbackEvent(String* name, Address entry_point);
216  void GetterCallbackEvent(String* name, Address entry_point);
217  void SetterCallbackEvent(String* name, Address entry_point);
218  // Emits a code create event.
219  void CodeCreateEvent(LogEventsAndTags tag,
220                       Code* code, const char* source);
221  void CodeCreateEvent(LogEventsAndTags tag,
222                       Code* code, String* name);
223  void CodeCreateEvent(LogEventsAndTags tag,
224                       Code* code,
225                       SharedFunctionInfo* shared,
226                       String* name);
227  void CodeCreateEvent(LogEventsAndTags tag,
228                       Code* code,
229                       SharedFunctionInfo* shared,
230                       String* source, int line);
231  void CodeCreateEvent(LogEventsAndTags tag, Code* code, int args_count);
232  void CodeMovingGCEvent();
233  // Emits a code create event for a RegExp.
234  void RegExpCodeCreateEvent(Code* code, String* source);
235  // Emits a code move event.
236  void CodeMoveEvent(Address from, Address to);
237  // Emits a code delete event.
238  void CodeDeleteEvent(Address from);
239
240  void SharedFunctionInfoMoveEvent(Address from, Address to);
241
242  void SnapshotPositionEvent(Address addr, int pos);
243
244  // ==== Events logged by --log-gc. ====
245  // Heap sampling events: start, end, and individual types.
246  void HeapSampleBeginEvent(const char* space, const char* kind);
247  void HeapSampleEndEvent(const char* space, const char* kind);
248  void HeapSampleItemEvent(const char* type, int number, int bytes);
249  void HeapSampleJSConstructorEvent(const char* constructor,
250                                    int number, int bytes);
251  void HeapSampleJSRetainersEvent(const char* constructor,
252                                         const char* event);
253  void HeapSampleJSProducerEvent(const char* constructor,
254                                 Address* stack);
255  void HeapSampleStats(const char* space, const char* kind,
256                       intptr_t capacity, intptr_t used);
257
258  void SharedLibraryEvent(const char* library_path,
259                          uintptr_t start,
260                          uintptr_t end);
261  void SharedLibraryEvent(const wchar_t* library_path,
262                          uintptr_t start,
263                          uintptr_t end);
264
265  // ==== Events logged by --log-regexp ====
266  // Regexp compilation and execution events.
267
268  void RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache);
269
270  // Log an event reported from generated code
271  void LogRuntime(Vector<const char> format, JSArray* args);
272
273  bool is_logging() {
274    return logging_nesting_ > 0;
275  }
276
277  // Pause/Resume collection of profiling data.
278  // When data collection is paused, CPU Tick events are discarded until
279  // data collection is Resumed.
280  void PauseProfiler();
281  void ResumeProfiler();
282  bool IsProfilerPaused();
283
284  void LogExistingFunction(Handle<SharedFunctionInfo> shared,
285                           Handle<Code> code);
286  // Logs all compiled functions found in the heap.
287  void LogCompiledFunctions();
288  // Logs all accessor callbacks found in the heap.
289  void LogAccessorCallbacks();
290  // Used for logging stubs found in the snapshot.
291  void LogCodeObjects();
292
293  // Converts tag to a corresponding NATIVE_... if the script is native.
294  INLINE(static LogEventsAndTags ToNativeByScript(LogEventsAndTags, Script*));
295
296  // Profiler's sampling interval (in milliseconds).
297#if defined(ANDROID)
298  // Phones and tablets have processors that are much slower than desktop
299  // and laptop computers for which current heuristics are tuned.
300  static const int kSamplingIntervalMs = 5;
301#else
302  static const int kSamplingIntervalMs = 1;
303#endif
304
305  // Callback from Log, stops profiling in case of insufficient resources.
306  void LogFailure();
307
308 private:
309  class NameBuffer;
310  class NameMap;
311
312  Logger();
313  ~Logger();
314
315  // Emits the profiler's first message.
316  void ProfilerBeginEvent();
317
318  // Emits callback event messages.
319  void CallbackEventInternal(const char* prefix,
320                             const char* name,
321                             Address entry_point);
322
323  // Internal configurable move event.
324  void MoveEventInternal(LogEventsAndTags event, Address from, Address to);
325
326  // Internal configurable move event.
327  void DeleteEventInternal(LogEventsAndTags event, Address from);
328
329  // Emits the source code of a regexp. Used by regexp events.
330  void LogRegExpSource(Handle<JSRegExp> regexp);
331
332  // Used for logging stubs found in the snapshot.
333  void LogCodeObject(Object* code_object);
334
335  // Emits general information about generated code.
336  void LogCodeInfo();
337
338  void RegisterSnapshotCodeName(Code* code, const char* name, int name_size);
339
340  // Low-level logging support.
341
342  void LowLevelCodeCreateEvent(Code* code, const char* name, int name_size);
343
344  void LowLevelCodeMoveEvent(Address from, Address to);
345
346  void LowLevelCodeDeleteEvent(Address from);
347
348  void LowLevelSnapshotPositionEvent(Address addr, int pos);
349
350  void LowLevelLogWriteBytes(const char* bytes, int size);
351
352  template <typename T>
353  void LowLevelLogWriteStruct(const T& s) {
354    char tag = T::kTag;
355    LowLevelLogWriteBytes(reinterpret_cast<const char*>(&tag), sizeof(tag));
356    LowLevelLogWriteBytes(reinterpret_cast<const char*>(&s), sizeof(s));
357  }
358
359  // Emits a profiler tick event. Used by the profiler thread.
360  void TickEvent(TickSample* sample, bool overflow);
361
362  void ApiEvent(const char* name, ...);
363
364  // Logs a StringEvent regardless of whether FLAG_log is true.
365  void UncheckedStringEvent(const char* name, const char* value);
366
367  // Logs an IntEvent regardless of whether FLAG_log is true.
368  void UncheckedIntEvent(const char* name, int value);
369  void UncheckedIntPtrTEvent(const char* name, intptr_t value);
370
371  // Returns whether profiler's sampler is active.
372  bool IsProfilerSamplerActive();
373
374  // The sampler used by the profiler and the sliding state window.
375  Ticker* ticker_;
376
377  // When the statistical profile is active, profiler_
378  // points to a Profiler, that handles collection
379  // of samples.
380  Profiler* profiler_;
381
382  // SlidingStateWindow instance keeping a sliding window of the most
383  // recent VM states.
384  SlidingStateWindow* sliding_state_window_;
385
386  // An array of log events names.
387  const char* const* log_events_;
388
389  // Internal implementation classes with access to
390  // private members.
391  friend class EventLog;
392  friend class Isolate;
393  friend class LogMessageBuilder;
394  friend class TimeLog;
395  friend class Profiler;
396  friend class SlidingStateWindow;
397  friend class StackTracer;
398  friend class VMState;
399
400  friend class LoggerTestHelper;
401
402
403  int logging_nesting_;
404  int cpu_profiler_nesting_;
405
406  Log* log_;
407
408  NameBuffer* name_buffer_;
409
410  NameMap* address_to_name_map_;
411
412  // Guards against multiple calls to TearDown() that can happen in some tests.
413  // 'true' between SetUp() and TearDown().
414  bool is_initialized_;
415
416  // Support for 'incremental addresses' in compressed logs:
417  //  LogMessageBuilder::AppendAddress(Address addr)
418  Address last_address_;
419  //  Logger::TickEvent(...)
420  Address prev_sp_;
421  Address prev_function_;
422  //  Logger::MoveEventInternal(...)
423  Address prev_to_;
424  //  Logger::FunctionCreateEvent(...)
425  Address prev_code_;
426
427  friend class CpuProfiler;
428};
429
430
431// Process wide registry of samplers.
432class SamplerRegistry : public AllStatic {
433 public:
434  enum State {
435    HAS_NO_SAMPLERS,
436    HAS_SAMPLERS,
437    HAS_CPU_PROFILING_SAMPLERS
438  };
439
440  typedef void (*VisitSampler)(Sampler*, void*);
441
442  static State GetState();
443
444  // Iterates over all active samplers keeping the internal lock held.
445  // Returns whether there are any active samplers.
446  static bool IterateActiveSamplers(VisitSampler func, void* param);
447
448  // Adds/Removes an active sampler.
449  static void AddActiveSampler(Sampler* sampler);
450  static void RemoveActiveSampler(Sampler* sampler);
451
452 private:
453  static bool ActiveSamplersExist() {
454    return active_samplers_ != NULL && !active_samplers_->is_empty();
455  }
456
457  static List<Sampler*>* active_samplers_;
458
459  DISALLOW_IMPLICIT_CONSTRUCTORS(SamplerRegistry);
460};
461
462
463// Class that extracts stack trace, used for profiling.
464class StackTracer : public AllStatic {
465 public:
466  static void Trace(Isolate* isolate, TickSample* sample);
467};
468
469} }  // namespace v8::internal
470
471
472#endif  // V8_LOG_H_
473