• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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 <set>
9 #include <string>
10 
11 #include "include/v8-profiler.h"
12 #include "src/allocation.h"
13 #include "src/base/compiler-specific.h"
14 #include "src/base/platform/elapsed-timer.h"
15 #include "src/base/platform/platform.h"
16 #include "src/code-events.h"
17 #include "src/isolate.h"
18 #include "src/log-utils.h"
19 #include "src/objects.h"
20 
21 namespace v8 {
22 
23 struct TickSample;
24 
25 namespace sampler {
26 class Sampler;
27 }
28 
29 namespace internal {
30 
31 // Logger is used for collecting logging information from V8 during
32 // execution. The result is dumped to a file.
33 //
34 // Available command line flags:
35 //
36 //  --log
37 // Minimal logging (no API, code, or GC sample events), default is off.
38 //
39 // --log-all
40 // Log all events to the file, default is off.  This is the same as combining
41 // --log-api, --log-code, and --log-regexp.
42 //
43 // --log-api
44 // Log API events to the logfile, default is off.  --log-api implies --log.
45 //
46 // --log-code
47 // Log code (create, move, and delete) events to the logfile, default is off.
48 // --log-code implies --log.
49 //
50 // --log-regexp
51 // Log creation and use of regular expressions, Default is off.
52 // --log-regexp implies --log.
53 //
54 // --logfile <filename>
55 // Specify the name of the logfile, default is "v8.log".
56 //
57 // --prof
58 // Collect statistical profiling information (ticks), default is off.  The
59 // tick profiler requires code events, so --prof implies --log-code.
60 //
61 // --prof-sampling-interval <microseconds>
62 // The interval between --prof samples, default is 1000 microseconds (5000 on
63 // Android).
64 
65 // Forward declarations.
66 class CodeEventListener;
67 class CpuProfiler;
68 class Isolate;
69 class JitLogger;
70 class Log;
71 class LowLevelLogger;
72 class PerfBasicLogger;
73 class PerfJitLogger;
74 class Profiler;
75 class RuntimeCallTimer;
76 class Ticker;
77 
78 namespace interpreter {
79 enum class Bytecode : uint8_t;
80 enum class OperandScale : uint8_t;
81 }  // namespace interpreter
82 
83 namespace wasm {
84 class WasmCode;
85 }
86 
87 #undef LOG
88 #define LOG(isolate, Call)                              \
89   do {                                                  \
90     v8::internal::Logger* logger = (isolate)->logger(); \
91     if (logger->is_logging()) logger->Call;             \
92   } while (false)
93 
94 #define LOG_CODE_EVENT(isolate, Call)                        \
95   do {                                                       \
96     v8::internal::Logger* logger = (isolate)->logger();      \
97     if (logger->is_listening_to_code_events()) logger->Call; \
98   } while (false)
99 
100 class ExistingCodeLogger {
101  public:
102   explicit ExistingCodeLogger(Isolate* isolate,
103                               CodeEventListener* listener = nullptr)
isolate_(isolate)104       : isolate_(isolate), listener_(listener) {}
105 
106   void LogCodeObjects();
107   void LogBytecodeHandlers();
108 
109   void LogCompiledFunctions();
110   void LogExistingFunction(Handle<SharedFunctionInfo> shared,
111                            Handle<AbstractCode> code,
112                            CodeEventListener::LogEventsAndTags tag =
113                                CodeEventListener::LAZY_COMPILE_TAG);
114   void LogCodeObject(Object* object);
115   void LogBytecodeHandler(interpreter::Bytecode bytecode,
116                           interpreter::OperandScale operand_scale, Code* code);
117 
118  private:
119   Isolate* isolate_;
120   CodeEventListener* listener_;
121 };
122 
123 class Logger : public CodeEventListener {
124  public:
125   enum StartEnd { START = 0, END = 1, STAMP = 2 };
126 
127   enum class ScriptEventType {
128     kReserveId,
129     kCreate,
130     kDeserialize,
131     kBackgroundCompile,
132     kStreamingCompile
133   };
134 
135   // The separator is used to write an unescaped "," into the log.
136   static const LogSeparator kNext = LogSeparator::kSeparator;
137 
138   // Acquires resources for logging if the right flags are set.
139   bool SetUp(Isolate* isolate);
140 
141   // Sets the current code event handler.
142   void SetCodeEventHandler(uint32_t options,
143                            JitCodeEventHandler event_handler);
144 
145   sampler::Sampler* sampler();
146 
147   void StopProfilerThread();
148 
149   // Frees resources acquired in SetUp.
150   // When a temporary file is used for the log, returns its stream descriptor,
151   // leaving the file open.
152   FILE* TearDown();
153 
154   // Emits an event with a string value -> (name, value).
155   void StringEvent(const char* name, const char* value);
156 
157   // Emits an event with an int value -> (name, value).
158   void IntPtrTEvent(const char* name, intptr_t value);
159 
160   // Emits an event with an handle value -> (name, location).
161   void HandleEvent(const char* name, Object** location);
162 
163   // Emits memory management events for C allocated structures.
164   void NewEvent(const char* name, void* object, size_t size);
165   void DeleteEvent(const char* name, void* object);
166 
167   // Emits an event with a tag, and some resource usage information.
168   // -> (name, tag, <rusage information>).
169   // Currently, the resource usage information is a process time stamp
170   // and a real time timestamp.
171   void ResourceEvent(const char* name, const char* tag);
172 
173   // Emits an event that an undefined property was read from an
174   // object.
175   void SuspectReadEvent(Name* name, Object* obj);
176 
177   // ==== Events logged by --log-function-events ====
178   void FunctionEvent(const char* reason, int script_id, double time_delta_ms,
179                      int start_position = -1, int end_position = -1,
180                      String* function_name = nullptr);
181   void FunctionEvent(const char* reason, int script_id, double time_delta_ms,
182                      int start_position, int end_position,
183                      const char* function_name = nullptr,
184                      size_t function_name_length = 0);
185 
186   void CompilationCacheEvent(const char* action, const char* cache_type,
187                              SharedFunctionInfo* sfi);
188   void ScriptEvent(ScriptEventType type, int script_id);
189   void ScriptDetails(Script* script);
190 
191   // ==== Events logged by --log-api. ====
192   void ApiSecurityCheck();
193   void ApiNamedPropertyAccess(const char* tag, JSObject* holder, Object* name);
194   void ApiIndexedPropertyAccess(const char* tag,
195                                 JSObject* holder,
196                                 uint32_t index);
197   void ApiObjectAccess(const char* tag, JSObject* obj);
198   void ApiEntryCall(const char* name);
199 
200   // ==== Events logged by --log-code. ====
201   void AddCodeEventListener(CodeEventListener* listener);
202   void RemoveCodeEventListener(CodeEventListener* listener);
203 
204   // Emits a code event for a callback function.
205   void CallbackEvent(Name* name, Address entry_point);
206   void GetterCallbackEvent(Name* name, Address entry_point);
207   void SetterCallbackEvent(Name* name, Address entry_point);
208   // Emits a code create event.
209   void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
210                        AbstractCode* code, const char* source);
211   void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
212                        AbstractCode* code, Name* name);
213   void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
214                        AbstractCode* code, SharedFunctionInfo* shared,
215                        Name* name);
216   void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
217                        AbstractCode* code, SharedFunctionInfo* shared,
218                        Name* source, int line, int column);
219   void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
220                        const wasm::WasmCode* code, wasm::WasmName name);
221   // Emits a code deoptimization event.
222   void CodeDisableOptEvent(AbstractCode* code, SharedFunctionInfo* shared);
223   void CodeMovingGCEvent();
224   // Emits a code create event for a RegExp.
225   void RegExpCodeCreateEvent(AbstractCode* code, String* source);
226   // Emits a code move event.
227   void CodeMoveEvent(AbstractCode* from, AbstractCode* to);
228   // Emits a code line info record event.
229   void CodeLinePosInfoRecordEvent(Address code_start,
230                                   ByteArray* source_position_table);
231   void CodeLinePosInfoRecordEvent(Address code_start,
232                                   Vector<const byte> source_position_table);
233 
234   void SharedFunctionInfoMoveEvent(Address from, Address to);
235 
236   void CodeNameEvent(Address addr, int pos, const char* code_name);
237 
238   void CodeDeoptEvent(Code* code, DeoptimizeKind kind, Address pc,
239                       int fp_to_sp_delta);
240 
241   void ICEvent(const char* type, bool keyed, Map* map, Object* key,
242                char old_state, char new_state, const char* modifier,
243                const char* slow_stub_reason);
244 
245   void MapEvent(const char* type, Map* from, Map* to,
246                 const char* reason = nullptr,
247                 HeapObject* name_or_sfi = nullptr);
248   void MapCreate(Map* map);
249   void MapDetails(Map* map);
250 
251 
252   void SharedLibraryEvent(const std::string& library_path, uintptr_t start,
253                           uintptr_t end, intptr_t aslr_slide);
254 
255   void CurrentTimeEvent();
256 
257   V8_EXPORT_PRIVATE void TimerEvent(StartEnd se, const char* name);
258 
259   static void EnterExternal(Isolate* isolate);
260   static void LeaveExternal(Isolate* isolate);
261 
DefaultEventLoggerSentinel(const char * name,int event)262   static void DefaultEventLoggerSentinel(const char* name, int event) {}
263 
264   V8_INLINE static void CallEventLogger(Isolate* isolate, const char* name,
265                                         StartEnd se, bool expose_to_api);
266 
is_logging()267   bool is_logging() {
268     return is_logging_;
269   }
270 
is_listening_to_code_events()271   bool is_listening_to_code_events() {
272     return is_logging() || jit_logger_ != nullptr;
273   }
274 
275   // Stop collection of profiling data.
276   // When data collection is paused, CPU Tick events are discarded.
277   void StopProfiler();
278 
279   void LogExistingFunction(Handle<SharedFunctionInfo> shared,
280                            Handle<AbstractCode> code);
281   // Logs all compiled functions found in the heap.
282   void LogCompiledFunctions();
283   // Logs all accessor callbacks found in the heap.
284   void LogAccessorCallbacks();
285   // Used for logging stubs found in the snapshot.
286   void LogCodeObjects();
287   // Used for logging bytecode handlers found in the snapshot.
288   void LogBytecodeHandlers();
289   void LogBytecodeHandler(interpreter::Bytecode bytecode,
290                           interpreter::OperandScale operand_scale, Code* code);
291   // Logs all Mpas foind in the heap.
292   void LogMaps();
293 
294   // Converts tag to a corresponding NATIVE_... if the script is native.
295   V8_INLINE static CodeEventListener::LogEventsAndTags ToNativeByScript(
296       CodeEventListener::LogEventsAndTags, Script*);
297 
298   // Callback from Log, stops profiling in case of insufficient resources.
299   void LogFailure();
300 
301   // Used for logging stubs found in the snapshot.
302   void LogCodeObject(Object* code_object);
303 
304  private:
305   explicit Logger(Isolate* isolate);
306   ~Logger();
307 
308   // Emits the profiler's first message.
309   void ProfilerBeginEvent();
310 
311   // Emits callback event messages.
312   void CallbackEventInternal(const char* prefix,
313                              Name* name,
314                              Address entry_point);
315 
316   // Internal configurable move event.
317   void MoveEventInternal(CodeEventListener::LogEventsAndTags event,
318                          Address from, Address to);
319 
320   // Helper method. It resets name_buffer_ and add tag name into it.
321   void InitNameBuffer(CodeEventListener::LogEventsAndTags tag);
322 
323   // Emits a profiler tick event. Used by the profiler thread.
324   void TickEvent(TickSample* sample, bool overflow);
325   void RuntimeCallTimerEvent();
326 
327   // Logs a StringEvent regardless of whether FLAG_log is true.
328   void UncheckedStringEvent(const char* name, const char* value);
329 
330   // Logs an IntPtrTEvent regardless of whether FLAG_log is true.
331   void UncheckedIntPtrTEvent(const char* name, intptr_t value);
332 
333   // Logs a scripts sources. Keeps track of all logged scripts to ensure that
334   // each script is logged only once.
335   bool EnsureLogScriptSource(Script* script);
336 
337   Isolate* isolate_;
338 
339   // The sampler used by the profiler and the sliding state window.
340   Ticker* ticker_;
341 
342   // When the statistical profile is active, profiler_
343   // points to a Profiler, that handles collection
344   // of samples.
345   Profiler* profiler_;
346 
347   // An array of log events names.
348   const char* const* log_events_;
349 
350   // Internal implementation classes with access to
351   // private members.
352   friend class EventLog;
353   friend class Isolate;
354   friend class TimeLog;
355   friend class Profiler;
356   template <StateTag Tag> friend class VMState;
357   friend class LoggerTestHelper;
358 
359   bool is_logging_;
360   Log* log_;
361   PerfBasicLogger* perf_basic_logger_;
362   PerfJitLogger* perf_jit_logger_;
363   LowLevelLogger* ll_logger_;
364   JitLogger* jit_logger_;
365   std::set<int> logged_source_code_;
366   uint32_t next_source_info_id_ = 0;
367 
368   // Guards against multiple calls to TearDown() that can happen in some tests.
369   // 'true' between SetUp() and TearDown().
370   bool is_initialized_;
371 
372   ExistingCodeLogger existing_code_logger_;
373 
374   base::ElapsedTimer timer_;
375 
376   friend class CpuProfiler;
377 };
378 
379 #define TIMER_EVENTS_LIST(V)     \
380   V(RecompileSynchronous, true)  \
381   V(RecompileConcurrent, true)   \
382   V(CompileIgnition, true)       \
383   V(CompileFullCode, true)       \
384   V(OptimizeCode, true)          \
385   V(CompileCode, true)           \
386   V(CompileCodeBackground, true) \
387   V(DeoptimizeCode, true)        \
388   V(Execute, true)               \
389   V(External, true)
390 
391 #define V(TimerName, expose)                          \
392   class TimerEvent##TimerName : public AllStatic {    \
393    public:                                            \
394     static const char* name(void* unused = nullptr) { \
395       return "V8." #TimerName;                        \
396     }                                                 \
397     static bool expose_to_api() { return expose; }    \
398   };
TIMER_EVENTS_LIST(V)399 TIMER_EVENTS_LIST(V)
400 #undef V
401 
402 
403 template <class TimerEvent>
404 class TimerEventScope {
405  public:
406   explicit TimerEventScope(Isolate* isolate) : isolate_(isolate) {
407     LogTimerEvent(Logger::START);
408   }
409 
410   ~TimerEventScope() { LogTimerEvent(Logger::END); }
411 
412  private:
413   void LogTimerEvent(Logger::StartEnd se);
414   Isolate* isolate_;
415 };
416 
417 class CodeEventLogger : public CodeEventListener {
418  public:
419   explicit CodeEventLogger(Isolate* isolate);
420   ~CodeEventLogger() override;
421 
422   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
423                        const char* comment) override;
424   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
425                        Name* name) override;
426   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
427                        SharedFunctionInfo* shared, Name* name) override;
428   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
429                        SharedFunctionInfo* shared, Name* source, int line,
430                        int column) override;
431   void CodeCreateEvent(LogEventsAndTags tag, const wasm::WasmCode* code,
432                        wasm::WasmName name) override;
433 
434   void RegExpCodeCreateEvent(AbstractCode* code, String* source) override;
CallbackEvent(Name * name,Address entry_point)435   void CallbackEvent(Name* name, Address entry_point) override {}
GetterCallbackEvent(Name * name,Address entry_point)436   void GetterCallbackEvent(Name* name, Address entry_point) override {}
SetterCallbackEvent(Name * name,Address entry_point)437   void SetterCallbackEvent(Name* name, Address entry_point) override {}
SharedFunctionInfoMoveEvent(Address from,Address to)438   void SharedFunctionInfoMoveEvent(Address from, Address to) override {}
CodeMovingGCEvent()439   void CodeMovingGCEvent() override {}
CodeDeoptEvent(Code * code,DeoptimizeKind kind,Address pc,int fp_to_sp_delta)440   void CodeDeoptEvent(Code* code, DeoptimizeKind kind, Address pc,
441                       int fp_to_sp_delta) override {}
442 
443  protected:
444   Isolate* isolate_;
445 
446  private:
447   class NameBuffer;
448 
449   virtual void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
450                                  const char* name, int length) = 0;
451   virtual void LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
452                                  int length) = 0;
453 
454   NameBuffer* name_buffer_;
455 };
456 
457 struct CodeEvent {
458   Isolate* isolate_;
459   uintptr_t code_start_address;
460   size_t code_size;
461   Handle<String> function_name;
462   Handle<String> script_name;
463   int script_line;
464   int script_column;
465   CodeEventType code_type;
466   const char* comment;
467 };
468 
469 class ExternalCodeEventListener : public CodeEventListener {
470  public:
471   explicit ExternalCodeEventListener(Isolate* isolate);
472   ~ExternalCodeEventListener() override;
473 
474   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
475                        const char* comment) override;
476   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
477                        Name* name) override;
478   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
479                        SharedFunctionInfo* shared, Name* name) override;
480   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
481                        SharedFunctionInfo* shared, Name* source, int line,
482                        int column) override;
483   void CodeCreateEvent(LogEventsAndTags tag, const wasm::WasmCode* code,
484                        wasm::WasmName name) override;
485 
486   void RegExpCodeCreateEvent(AbstractCode* code, String* source) override;
CallbackEvent(Name * name,Address entry_point)487   void CallbackEvent(Name* name, Address entry_point) override {}
GetterCallbackEvent(Name * name,Address entry_point)488   void GetterCallbackEvent(Name* name, Address entry_point) override {}
SetterCallbackEvent(Name * name,Address entry_point)489   void SetterCallbackEvent(Name* name, Address entry_point) override {}
SharedFunctionInfoMoveEvent(Address from,Address to)490   void SharedFunctionInfoMoveEvent(Address from, Address to) override {}
CodeMoveEvent(AbstractCode * from,AbstractCode * to)491   void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override {}
CodeDisableOptEvent(AbstractCode * code,SharedFunctionInfo * shared)492   void CodeDisableOptEvent(AbstractCode* code,
493                            SharedFunctionInfo* shared) override {}
CodeMovingGCEvent()494   void CodeMovingGCEvent() override {}
CodeDeoptEvent(Code * code,DeoptimizeKind kind,Address pc,int fp_to_sp_delta)495   void CodeDeoptEvent(Code* code, DeoptimizeKind kind, Address pc,
496                       int fp_to_sp_delta) override {}
497 
498   void StartListening(CodeEventHandler* code_event_handler);
499   void StopListening();
500 
is_listening_to_code_events()501   bool is_listening_to_code_events() override { return true; }
502 
503  private:
504   void LogExistingCode();
505 
506   bool is_listening_;
507   Isolate* isolate_;
508   v8::CodeEventHandler* code_event_handler_;
509 };
510 
511 }  // namespace internal
512 }  // namespace v8
513 
514 
515 #endif  // V8_LOG_H_
516