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