1 // Copyright 2012 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 #ifndef V8_LOG_H_
6 #define V8_LOG_H_
7 
8 #include <string>
9 
10 #include "src/allocation.h"
11 #include "src/base/compiler-specific.h"
12 #include "src/base/platform/elapsed-timer.h"
13 #include "src/base/platform/platform.h"
14 #include "src/code-events.h"
15 #include "src/isolate.h"
16 #include "src/objects.h"
17 
18 namespace v8 {
19 
20 struct TickSample;
21 
22 namespace sampler {
23 class Sampler;
24 }
25 
26 namespace internal {
27 
28 // Logger is used for collecting logging information from V8 during
29 // execution. The result is dumped to a file.
30 //
31 // Available command line flags:
32 //
33 //  --log
34 // Minimal logging (no API, code, or GC sample events), default is off.
35 //
36 // --log-all
37 // Log all events to the file, default is off.  This is the same as combining
38 // --log-api, --log-code, --log-gc, and --log-regexp.
39 //
40 // --log-api
41 // Log API events to the logfile, default is off.  --log-api implies --log.
42 //
43 // --log-code
44 // Log code (create, move, and delete) events to the logfile, default is off.
45 // --log-code implies --log.
46 //
47 // --log-gc
48 // Log GC heap samples after each GC that can be processed by hp2ps, default
49 // is off.  --log-gc implies --log.
50 //
51 // --log-regexp
52 // Log creation and use of regular expressions, Default is off.
53 // --log-regexp implies --log.
54 //
55 // --logfile <filename>
56 // Specify the name of the logfile, default is "v8.log".
57 //
58 // --prof
59 // Collect statistical profiling information (ticks), default is off.  The
60 // tick profiler requires code events, so --prof implies --log-code.
61 
62 // Forward declarations.
63 class CodeEventListener;
64 class CpuProfiler;
65 class Isolate;
66 class JitLogger;
67 class Log;
68 class LowLevelLogger;
69 class PerfBasicLogger;
70 class PerfJitLogger;
71 class Profiler;
72 class ProfilerListener;
73 class RuntimeCallTimer;
74 class Ticker;
75 
76 #undef LOG
77 #define LOG(isolate, Call)                              \
78   do {                                                  \
79     v8::internal::Logger* logger = (isolate)->logger(); \
80     if (logger->is_logging()) logger->Call;             \
81   } while (false)
82 
83 #define LOG_CODE_EVENT(isolate, Call)                   \
84   do {                                                  \
85     v8::internal::Logger* logger = (isolate)->logger(); \
86     if (logger->is_logging_code_events()) logger->Call; \
87   } while (false)
88 
89 class Logger : public CodeEventListener {
90  public:
91   enum StartEnd { START = 0, END = 1 };
92 
93   // Acquires resources for logging if the right flags are set.
94   bool SetUp(Isolate* isolate);
95 
96   // Sets the current code event handler.
97   void SetCodeEventHandler(uint32_t options,
98                            JitCodeEventHandler event_handler);
99 
100   // Sets up ProfilerListener.
101   void SetUpProfilerListener();
102 
103   // Tear down ProfilerListener if it has no observers.
104   void TearDownProfilerListener();
105 
106   sampler::Sampler* sampler();
107 
profiler_listener()108   ProfilerListener* profiler_listener() { return profiler_listener_.get(); }
109 
110   // Frees resources acquired in SetUp.
111   // When a temporary file is used for the log, returns its stream descriptor,
112   // leaving the file open.
113   FILE* TearDown();
114 
115   // Emits an event with a string value -> (name, value).
116   void StringEvent(const char* name, const char* value);
117 
118   // Emits an event with an int value -> (name, value).
119   void IntEvent(const char* name, int value);
120   void IntPtrTEvent(const char* name, intptr_t value);
121 
122   // Emits an event with an handle value -> (name, location).
123   void HandleEvent(const char* name, Object** location);
124 
125   // Emits memory management events for C allocated structures.
126   void NewEvent(const char* name, void* object, size_t size);
127   void DeleteEvent(const char* name, void* object);
128 
129   // Emits an event with a tag, and some resource usage information.
130   // -> (name, tag, <rusage information>).
131   // Currently, the resource usage information is a process time stamp
132   // and a real time timestamp.
133   void ResourceEvent(const char* name, const char* tag);
134 
135   // Emits an event that an undefined property was read from an
136   // object.
137   void SuspectReadEvent(Name* name, Object* obj);
138 
139   // ==== Events logged by --log-api. ====
140   void ApiSecurityCheck();
141   void ApiNamedPropertyAccess(const char* tag, JSObject* holder, Object* name);
142   void ApiIndexedPropertyAccess(const char* tag,
143                                 JSObject* holder,
144                                 uint32_t index);
145   void ApiObjectAccess(const char* tag, JSObject* obj);
146   void ApiEntryCall(const char* name);
147 
148   // ==== Events logged by --log-code. ====
149   void addCodeEventListener(CodeEventListener* listener);
150   void removeCodeEventListener(CodeEventListener* listener);
151 
152   // Emits a code event for a callback function.
153   void CallbackEvent(Name* name, Address entry_point);
154   void GetterCallbackEvent(Name* name, Address entry_point);
155   void SetterCallbackEvent(Name* name, Address entry_point);
156   // Emits a code create event.
157   void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
158                        AbstractCode* code, const char* source);
159   void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
160                        AbstractCode* code, Name* name);
161   void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
162                        AbstractCode* code, SharedFunctionInfo* shared,
163                        Name* name);
164   void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
165                        AbstractCode* code, SharedFunctionInfo* shared,
166                        Name* source, int line, int column);
167   void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
168                        AbstractCode* code, int args_count);
169   // Emits a code deoptimization event.
170   void CodeDisableOptEvent(AbstractCode* code, SharedFunctionInfo* shared);
171   void CodeMovingGCEvent();
172   // Emits a code create event for a RegExp.
173   void RegExpCodeCreateEvent(AbstractCode* code, String* source);
174   // Emits a code move event.
175   void CodeMoveEvent(AbstractCode* from, Address to);
176   // Emits a code line info record event.
177   void CodeLinePosInfoRecordEvent(AbstractCode* code,
178                                   ByteArray* source_position_table);
179 
180   void SharedFunctionInfoMoveEvent(Address from, Address to);
181 
182   void CodeNameEvent(Address addr, int pos, const char* code_name);
183 
184   void CodeDeoptEvent(Code* code, Address pc, int fp_to_sp_delta);
185 
186   void ICEvent(const char* type, bool keyed, const Address pc, int line,
187                int column, Map* map, Object* key, char old_state,
188                char new_state, const char* modifier,
189                const char* slow_stub_reason);
190   void CompareIC(const Address pc, int line, int column, Code* stub,
191                  const char* op, const char* old_left, const char* old_right,
192                  const char* old_state, const char* new_left,
193                  const char* new_right, const char* new_state);
194   void BinaryOpIC(const Address pc, int line, int column, Code* stub,
195                   const char* old_state, const char* new_state,
196                   AllocationSite* allocation_site);
197   void ToBooleanIC(const Address pc, int line, int column, Code* stub,
198                    const char* old_state, const char* new_state);
199   void PatchIC(const Address pc, const Address test, int delta);
200 
201   // ==== Events logged by --log-gc. ====
202   // Heap sampling events: start, end, and individual types.
203   void HeapSampleBeginEvent(const char* space, const char* kind);
204   void HeapSampleEndEvent(const char* space, const char* kind);
205   void HeapSampleItemEvent(const char* type, int number, int bytes);
206   void HeapSampleJSConstructorEvent(const char* constructor,
207                                     int number, int bytes);
208   void HeapSampleJSRetainersEvent(const char* constructor,
209                                          const char* event);
210   void HeapSampleJSProducerEvent(const char* constructor,
211                                  Address* stack);
212   void HeapSampleStats(const char* space, const char* kind,
213                        intptr_t capacity, intptr_t used);
214 
215   void SharedLibraryEvent(const std::string& library_path, uintptr_t start,
216                           uintptr_t end, intptr_t aslr_slide);
217 
218   void CurrentTimeEvent();
219 
220   void TimerEvent(StartEnd se, const char* name);
221 
222   static void EnterExternal(Isolate* isolate);
223   static void LeaveExternal(Isolate* isolate);
224 
DefaultEventLoggerSentinel(const char * name,int event)225   static void DefaultEventLoggerSentinel(const char* name, int event) {}
226 
227   INLINE(static void CallEventLogger(Isolate* isolate, const char* name,
228                                      StartEnd se, bool expose_to_api));
229 
is_logging()230   bool is_logging() {
231     return is_logging_;
232   }
233 
is_logging_code_events()234   bool is_logging_code_events() {
235     return is_logging() || jit_logger_ != NULL;
236   }
237 
238   // Stop collection of profiling data.
239   // When data collection is paused, CPU Tick events are discarded.
240   void StopProfiler();
241 
242   void LogExistingFunction(Handle<SharedFunctionInfo> shared,
243                            Handle<AbstractCode> code);
244   // Logs all compiled functions found in the heap.
245   void LogCompiledFunctions();
246   // Logs all accessor callbacks found in the heap.
247   void LogAccessorCallbacks();
248   // Used for logging stubs found in the snapshot.
249   void LogCodeObjects();
250   // Used for logging bytecode handlers found in the snapshot.
251   void LogBytecodeHandlers();
252 
253   // Converts tag to a corresponding NATIVE_... if the script is native.
254   INLINE(static CodeEventListener::LogEventsAndTags ToNativeByScript(
255       CodeEventListener::LogEventsAndTags, Script*));
256 
257   // Profiler's sampling interval (in milliseconds).
258 #if defined(ANDROID)
259   // Phones and tablets have processors that are much slower than desktop
260   // and laptop computers for which current heuristics are tuned.
261   static const int kSamplingIntervalMs = 5;
262 #else
263   static const int kSamplingIntervalMs = 1;
264 #endif
265 
266   // Callback from Log, stops profiling in case of insufficient resources.
267   void LogFailure();
268 
269  private:
270   explicit Logger(Isolate* isolate);
271   ~Logger();
272 
273   // Emits the profiler's first message.
274   void ProfilerBeginEvent();
275 
276   // Emits callback event messages.
277   void CallbackEventInternal(const char* prefix,
278                              Name* name,
279                              Address entry_point);
280 
281   // Internal configurable move event.
282   void MoveEventInternal(CodeEventListener::LogEventsAndTags event,
283                          Address from, Address to);
284 
285   // Used for logging stubs found in the snapshot.
286   void LogCodeObject(Object* code_object);
287 
288   // Helper method. It resets name_buffer_ and add tag name into it.
289   void InitNameBuffer(CodeEventListener::LogEventsAndTags tag);
290 
291   // Emits a profiler tick event. Used by the profiler thread.
292   void TickEvent(TickSample* sample, bool overflow);
293   void RuntimeCallTimerEvent();
294 
295   PRINTF_FORMAT(2, 3) void ApiEvent(const char* format, ...);
296 
297   // Logs a StringEvent regardless of whether FLAG_log is true.
298   void UncheckedStringEvent(const char* name, const char* value);
299 
300   // Logs an IntEvent regardless of whether FLAG_log is true.
301   void UncheckedIntEvent(const char* name, int value);
302   void UncheckedIntPtrTEvent(const char* name, intptr_t value);
303 
304   Isolate* isolate_;
305 
306   // The sampler used by the profiler and the sliding state window.
307   Ticker* ticker_;
308 
309   // When the statistical profile is active, profiler_
310   // points to a Profiler, that handles collection
311   // of samples.
312   Profiler* profiler_;
313 
314   // An array of log events names.
315   const char* const* log_events_;
316 
317   // Internal implementation classes with access to
318   // private members.
319   friend class EventLog;
320   friend class Isolate;
321   friend class TimeLog;
322   friend class Profiler;
323   template <StateTag Tag> friend class VMState;
324   friend class LoggerTestHelper;
325 
326   bool is_logging_;
327   Log* log_;
328   PerfBasicLogger* perf_basic_logger_;
329   PerfJitLogger* perf_jit_logger_;
330   LowLevelLogger* ll_logger_;
331   JitLogger* jit_logger_;
332   std::unique_ptr<ProfilerListener> profiler_listener_;
333   List<CodeEventListener*> listeners_;
334 
335   // Guards against multiple calls to TearDown() that can happen in some tests.
336   // 'true' between SetUp() and TearDown().
337   bool is_initialized_;
338 
339   base::ElapsedTimer timer_;
340 
341   friend class CpuProfiler;
342 };
343 
344 #define TIMER_EVENTS_LIST(V)    \
345   V(RecompileSynchronous, true) \
346   V(RecompileConcurrent, true)  \
347   V(CompileIgnition, true)      \
348   V(CompileFullCode, true)      \
349   V(OptimizeCode, true)         \
350   V(CompileCode, true)          \
351   V(DeoptimizeCode, true)       \
352   V(Execute, true)              \
353   V(External, true)
354 
355 #define V(TimerName, expose)                                                  \
356   class TimerEvent##TimerName : public AllStatic {                            \
357    public:                                                                    \
358     static const char* name(void* unused = NULL) { return "V8." #TimerName; } \
359     static bool expose_to_api() { return expose; }                            \
360   };
TIMER_EVENTS_LIST(V)361 TIMER_EVENTS_LIST(V)
362 #undef V
363 
364 
365 template <class TimerEvent>
366 class TimerEventScope {
367  public:
368   explicit TimerEventScope(Isolate* isolate) : isolate_(isolate) {
369     LogTimerEvent(Logger::START);
370   }
371 
372   ~TimerEventScope() { LogTimerEvent(Logger::END); }
373 
374  private:
375   void LogTimerEvent(Logger::StartEnd se);
376   Isolate* isolate_;
377 };
378 
379 class CodeEventLogger : public CodeEventListener {
380  public:
381   CodeEventLogger();
382   ~CodeEventLogger() override;
383 
384   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
385                        const char* comment) override;
386   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
387                        Name* name) override;
388   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
389                        int args_count) override;
390   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
391                        SharedFunctionInfo* shared, Name* name) override;
392   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
393                        SharedFunctionInfo* shared, Name* source, int line,
394                        int column) override;
395   void RegExpCodeCreateEvent(AbstractCode* code, String* source) override;
396 
CallbackEvent(Name * name,Address entry_point)397   void CallbackEvent(Name* name, Address entry_point) override {}
GetterCallbackEvent(Name * name,Address entry_point)398   void GetterCallbackEvent(Name* name, Address entry_point) override {}
SetterCallbackEvent(Name * name,Address entry_point)399   void SetterCallbackEvent(Name* name, Address entry_point) override {}
SharedFunctionInfoMoveEvent(Address from,Address to)400   void SharedFunctionInfoMoveEvent(Address from, Address to) override {}
CodeMovingGCEvent()401   void CodeMovingGCEvent() override {}
CodeDeoptEvent(Code * code,Address pc,int fp_to_sp_delta)402   void CodeDeoptEvent(Code* code, Address pc, int fp_to_sp_delta) override {}
403 
404  private:
405   class NameBuffer;
406 
407   virtual void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
408                                  const char* name, int length) = 0;
409 
410   NameBuffer* name_buffer_;
411 };
412 
413 
414 }  // namespace internal
415 }  // namespace v8
416 
417 
418 #endif  // V8_LOG_H_
419