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