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/platform/elapsed-timer.h" 12 #include "src/base/platform/platform.h" 13 #include "src/objects.h" 14 15 namespace v8 { 16 17 namespace base { 18 class Semaphore; 19 } 20 21 namespace internal { 22 23 // Logger is used for collecting logging information from V8 during 24 // execution. The result is dumped to a file. 25 // 26 // Available command line flags: 27 // 28 // --log 29 // Minimal logging (no API, code, or GC sample events), default is off. 30 // 31 // --log-all 32 // Log all events to the file, default is off. This is the same as combining 33 // --log-api, --log-code, --log-gc, and --log-regexp. 34 // 35 // --log-api 36 // Log API events to the logfile, default is off. --log-api implies --log. 37 // 38 // --log-code 39 // Log code (create, move, and delete) events to the logfile, default is off. 40 // --log-code implies --log. 41 // 42 // --log-gc 43 // Log GC heap samples after each GC that can be processed by hp2ps, default 44 // is off. --log-gc implies --log. 45 // 46 // --log-regexp 47 // Log creation and use of regular expressions, Default is off. 48 // --log-regexp implies --log. 49 // 50 // --logfile <filename> 51 // Specify the name of the logfile, default is "v8.log". 52 // 53 // --prof 54 // Collect statistical profiling information (ticks), default is off. The 55 // tick profiler requires code events, so --prof implies --log-code. 56 57 // Forward declarations. 58 class CodeEventListener; 59 class CompilationInfo; 60 class CpuProfiler; 61 class Isolate; 62 class Log; 63 class PositionsRecorder; 64 class Profiler; 65 class Ticker; 66 struct TickSample; 67 68 #undef LOG 69 #define LOG(isolate, Call) \ 70 do { \ 71 v8::internal::Logger* logger = \ 72 (isolate)->logger(); \ 73 if (logger->is_logging()) \ 74 logger->Call; \ 75 } while (false) 76 77 #define LOG_CODE_EVENT(isolate, Call) \ 78 do { \ 79 v8::internal::Logger* logger = \ 80 (isolate)->logger(); \ 81 if (logger->is_logging_code_events()) \ 82 logger->Call; \ 83 } while (false) 84 85 86 #define LOG_EVENTS_AND_TAGS_LIST(V) \ 87 V(CODE_CREATION_EVENT, "code-creation") \ 88 V(CODE_DISABLE_OPT_EVENT, "code-disable-optimization") \ 89 V(CODE_MOVE_EVENT, "code-move") \ 90 V(CODE_DELETE_EVENT, "code-delete") \ 91 V(CODE_MOVING_GC, "code-moving-gc") \ 92 V(SHARED_FUNC_MOVE_EVENT, "sfi-move") \ 93 V(SNAPSHOT_POSITION_EVENT, "snapshot-pos") \ 94 V(SNAPSHOT_CODE_NAME_EVENT, "snapshot-code-name") \ 95 V(TICK_EVENT, "tick") \ 96 V(REPEAT_META_EVENT, "repeat") \ 97 V(BUILTIN_TAG, "Builtin") \ 98 V(CALL_DEBUG_BREAK_TAG, "CallDebugBreak") \ 99 V(CALL_DEBUG_PREPARE_STEP_IN_TAG, "CallDebugPrepareStepIn") \ 100 V(CALL_INITIALIZE_TAG, "CallInitialize") \ 101 V(CALL_MEGAMORPHIC_TAG, "CallMegamorphic") \ 102 V(CALL_MISS_TAG, "CallMiss") \ 103 V(CALL_NORMAL_TAG, "CallNormal") \ 104 V(CALL_PRE_MONOMORPHIC_TAG, "CallPreMonomorphic") \ 105 V(LOAD_INITIALIZE_TAG, "LoadInitialize") \ 106 V(LOAD_PREMONOMORPHIC_TAG, "LoadPreMonomorphic") \ 107 V(LOAD_MEGAMORPHIC_TAG, "LoadMegamorphic") \ 108 V(STORE_INITIALIZE_TAG, "StoreInitialize") \ 109 V(STORE_PREMONOMORPHIC_TAG, "StorePreMonomorphic") \ 110 V(STORE_GENERIC_TAG, "StoreGeneric") \ 111 V(STORE_MEGAMORPHIC_TAG, "StoreMegamorphic") \ 112 V(KEYED_CALL_DEBUG_BREAK_TAG, "KeyedCallDebugBreak") \ 113 V(KEYED_CALL_DEBUG_PREPARE_STEP_IN_TAG, \ 114 "KeyedCallDebugPrepareStepIn") \ 115 V(KEYED_CALL_INITIALIZE_TAG, "KeyedCallInitialize") \ 116 V(KEYED_CALL_MEGAMORPHIC_TAG, "KeyedCallMegamorphic") \ 117 V(KEYED_CALL_MISS_TAG, "KeyedCallMiss") \ 118 V(KEYED_CALL_NORMAL_TAG, "KeyedCallNormal") \ 119 V(KEYED_CALL_PRE_MONOMORPHIC_TAG, "KeyedCallPreMonomorphic") \ 120 V(CALLBACK_TAG, "Callback") \ 121 V(EVAL_TAG, "Eval") \ 122 V(FUNCTION_TAG, "Function") \ 123 V(HANDLER_TAG, "Handler") \ 124 V(KEYED_LOAD_IC_TAG, "KeyedLoadIC") \ 125 V(KEYED_LOAD_POLYMORPHIC_IC_TAG, "KeyedLoadPolymorphicIC") \ 126 V(KEYED_EXTERNAL_ARRAY_LOAD_IC_TAG, "KeyedExternalArrayLoadIC") \ 127 V(KEYED_STORE_IC_TAG, "KeyedStoreIC") \ 128 V(KEYED_STORE_POLYMORPHIC_IC_TAG, "KeyedStorePolymorphicIC") \ 129 V(KEYED_EXTERNAL_ARRAY_STORE_IC_TAG, "KeyedExternalArrayStoreIC") \ 130 V(LAZY_COMPILE_TAG, "LazyCompile") \ 131 V(CALL_IC_TAG, "CallIC") \ 132 V(LOAD_IC_TAG, "LoadIC") \ 133 V(LOAD_POLYMORPHIC_IC_TAG, "LoadPolymorphicIC") \ 134 V(REG_EXP_TAG, "RegExp") \ 135 V(SCRIPT_TAG, "Script") \ 136 V(STORE_IC_TAG, "StoreIC") \ 137 V(STORE_POLYMORPHIC_IC_TAG, "StorePolymorphicIC") \ 138 V(STUB_TAG, "Stub") \ 139 V(NATIVE_FUNCTION_TAG, "Function") \ 140 V(NATIVE_LAZY_COMPILE_TAG, "LazyCompile") \ 141 V(NATIVE_SCRIPT_TAG, "Script") 142 // Note that 'NATIVE_' cases for functions and scripts are mapped onto 143 // original tags when writing to the log. 144 145 146 class JitLogger; 147 class PerfBasicLogger; 148 class LowLevelLogger; 149 class PerfJitLogger; 150 class Sampler; 151 152 class Logger { 153 public: 154 enum StartEnd { START = 0, END = 1 }; 155 156 #define DECLARE_ENUM(enum_item, ignore) enum_item, 157 enum LogEventsAndTags { 158 LOG_EVENTS_AND_TAGS_LIST(DECLARE_ENUM) 159 NUMBER_OF_LOG_EVENTS 160 }; 161 #undef DECLARE_ENUM 162 163 // Acquires resources for logging if the right flags are set. 164 bool SetUp(Isolate* isolate); 165 166 // Sets the current code event handler. 167 void SetCodeEventHandler(uint32_t options, 168 JitCodeEventHandler event_handler); 169 170 Sampler* sampler(); 171 172 // Frees resources acquired in SetUp. 173 // When a temporary file is used for the log, returns its stream descriptor, 174 // leaving the file open. 175 FILE* TearDown(); 176 177 // Emits an event with a string value -> (name, value). 178 void StringEvent(const char* name, const char* value); 179 180 // Emits an event with an int value -> (name, value). 181 void IntEvent(const char* name, int value); 182 void IntPtrTEvent(const char* name, intptr_t value); 183 184 // Emits an event with an handle value -> (name, location). 185 void HandleEvent(const char* name, Object** location); 186 187 // Emits memory management events for C allocated structures. 188 void NewEvent(const char* name, void* object, size_t size); 189 void DeleteEvent(const char* name, void* object); 190 191 // Static versions of the above, operate on current isolate's logger. 192 // Used in TRACK_MEMORY(TypeName) defined in globals.h 193 static void NewEventStatic(const char* name, void* object, size_t size); 194 static void DeleteEventStatic(const char* name, void* object); 195 196 // Emits an event with a tag, and some resource usage information. 197 // -> (name, tag, <rusage information>). 198 // Currently, the resource usage information is a process time stamp 199 // and a real time timestamp. 200 void ResourceEvent(const char* name, const char* tag); 201 202 // Emits an event that an undefined property was read from an 203 // object. 204 void SuspectReadEvent(Name* name, Object* obj); 205 206 // Emits an event when a message is put on or read from a debugging queue. 207 // DebugTag lets us put a call-site specific label on the event. 208 void DebugTag(const char* call_site_tag); 209 void DebugEvent(const char* event_type, Vector<uint16_t> parameter); 210 211 212 // ==== Events logged by --log-api. ==== 213 void ApiNamedSecurityCheck(Object* key); 214 void ApiIndexedSecurityCheck(uint32_t index); 215 void ApiNamedPropertyAccess(const char* tag, JSObject* holder, Object* name); 216 void ApiIndexedPropertyAccess(const char* tag, 217 JSObject* holder, 218 uint32_t index); 219 void ApiObjectAccess(const char* tag, JSObject* obj); 220 void ApiEntryCall(const char* name); 221 222 223 // ==== Events logged by --log-code. ==== 224 void addCodeEventListener(CodeEventListener* listener); 225 void removeCodeEventListener(CodeEventListener* listener); 226 bool hasCodeEventListener(CodeEventListener* listener); 227 228 229 // Emits a code event for a callback function. 230 void CallbackEvent(Name* name, Address entry_point); 231 void GetterCallbackEvent(Name* name, Address entry_point); 232 void SetterCallbackEvent(Name* name, Address entry_point); 233 // Emits a code create event. 234 void CodeCreateEvent(LogEventsAndTags tag, 235 Code* code, const char* source); 236 void CodeCreateEvent(LogEventsAndTags tag, 237 Code* code, Name* name); 238 void CodeCreateEvent(LogEventsAndTags tag, 239 Code* code, 240 SharedFunctionInfo* shared, 241 CompilationInfo* info, 242 Name* name); 243 void CodeCreateEvent(LogEventsAndTags tag, 244 Code* code, 245 SharedFunctionInfo* shared, 246 CompilationInfo* info, 247 Name* source, int line, int column); 248 void CodeCreateEvent(LogEventsAndTags tag, Code* code, int args_count); 249 // Emits a code deoptimization event. 250 void CodeDisableOptEvent(Code* code, SharedFunctionInfo* shared); 251 void CodeMovingGCEvent(); 252 // Emits a code create event for a RegExp. 253 void RegExpCodeCreateEvent(Code* code, String* source); 254 // Emits a code move event. 255 void CodeMoveEvent(Address from, Address to); 256 // Emits a code delete event. 257 void CodeDeleteEvent(Address from); 258 // Emits a code line info add event with Postion type. 259 void CodeLinePosInfoAddPositionEvent(void* jit_handler_data, 260 int pc_offset, 261 int position); 262 // Emits a code line info add event with StatementPostion type. 263 void CodeLinePosInfoAddStatementPositionEvent(void* jit_handler_data, 264 int pc_offset, 265 int position); 266 // Emits a code line info start to record event 267 void CodeStartLinePosInfoRecordEvent(PositionsRecorder* pos_recorder); 268 // Emits a code line info finish record event. 269 // It's the callee's responsibility to dispose the parameter jit_handler_data. 270 void CodeEndLinePosInfoRecordEvent(Code* code, void* jit_handler_data); 271 272 void SharedFunctionInfoMoveEvent(Address from, Address to); 273 274 void CodeNameEvent(Address addr, int pos, const char* code_name); 275 void SnapshotPositionEvent(Address addr, int pos); 276 277 // ==== Events logged by --log-gc. ==== 278 // Heap sampling events: start, end, and individual types. 279 void HeapSampleBeginEvent(const char* space, const char* kind); 280 void HeapSampleEndEvent(const char* space, const char* kind); 281 void HeapSampleItemEvent(const char* type, int number, int bytes); 282 void HeapSampleJSConstructorEvent(const char* constructor, 283 int number, int bytes); 284 void HeapSampleJSRetainersEvent(const char* constructor, 285 const char* event); 286 void HeapSampleJSProducerEvent(const char* constructor, 287 Address* stack); 288 void HeapSampleStats(const char* space, const char* kind, 289 intptr_t capacity, intptr_t used); 290 291 void SharedLibraryEvent(const std::string& library_path, 292 uintptr_t start, 293 uintptr_t end); 294 295 void CodeDeoptEvent(Code* code); 296 void CurrentTimeEvent(); 297 298 void TimerEvent(StartEnd se, const char* name); 299 300 static void EnterExternal(Isolate* isolate); 301 static void LeaveExternal(Isolate* isolate); 302 303 static void EmptyTimerEventsLogger(const char* name, int se) {} 304 static void DefaultTimerEventsLogger(const char* name, int se); 305 306 // ==== Events logged by --log-regexp ==== 307 // Regexp compilation and execution events. 308 309 void RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache); 310 311 bool is_logging() { 312 return is_logging_; 313 } 314 315 bool is_logging_code_events() { 316 return is_logging() || jit_logger_ != NULL; 317 } 318 319 // Stop collection of profiling data. 320 // When data collection is paused, CPU Tick events are discarded. 321 void StopProfiler(); 322 323 void LogExistingFunction(Handle<SharedFunctionInfo> shared, 324 Handle<Code> code); 325 // Logs all compiled functions found in the heap. 326 void LogCompiledFunctions(); 327 // Logs all accessor callbacks found in the heap. 328 void LogAccessorCallbacks(); 329 // Used for logging stubs found in the snapshot. 330 void LogCodeObjects(); 331 332 // Converts tag to a corresponding NATIVE_... if the script is native. 333 INLINE(static LogEventsAndTags ToNativeByScript(LogEventsAndTags, Script*)); 334 335 // Profiler's sampling interval (in milliseconds). 336 #if defined(ANDROID) 337 // Phones and tablets have processors that are much slower than desktop 338 // and laptop computers for which current heuristics are tuned. 339 static const int kSamplingIntervalMs = 5; 340 #else 341 static const int kSamplingIntervalMs = 1; 342 #endif 343 344 // Callback from Log, stops profiling in case of insufficient resources. 345 void LogFailure(); 346 347 private: 348 explicit Logger(Isolate* isolate); 349 ~Logger(); 350 351 // Emits the profiler's first message. 352 void ProfilerBeginEvent(); 353 354 // Emits callback event messages. 355 void CallbackEventInternal(const char* prefix, 356 Name* name, 357 Address entry_point); 358 359 // Internal configurable move event. 360 void MoveEventInternal(LogEventsAndTags event, Address from, Address to); 361 362 // Emits the source code of a regexp. Used by regexp events. 363 void LogRegExpSource(Handle<JSRegExp> regexp); 364 365 // Used for logging stubs found in the snapshot. 366 void LogCodeObject(Object* code_object); 367 368 // Helper method. It resets name_buffer_ and add tag name into it. 369 void InitNameBuffer(LogEventsAndTags tag); 370 371 // Emits a profiler tick event. Used by the profiler thread. 372 void TickEvent(TickSample* sample, bool overflow); 373 374 void ApiEvent(const char* name, ...); 375 376 // Logs a StringEvent regardless of whether FLAG_log is true. 377 void UncheckedStringEvent(const char* name, const char* value); 378 379 // Logs an IntEvent regardless of whether FLAG_log is true. 380 void UncheckedIntEvent(const char* name, int value); 381 void UncheckedIntPtrTEvent(const char* name, intptr_t value); 382 383 Isolate* isolate_; 384 385 // The sampler used by the profiler and the sliding state window. 386 Ticker* ticker_; 387 388 // When the statistical profile is active, profiler_ 389 // points to a Profiler, that handles collection 390 // of samples. 391 Profiler* profiler_; 392 393 // An array of log events names. 394 const char* const* log_events_; 395 396 // Internal implementation classes with access to 397 // private members. 398 friend class EventLog; 399 friend class Isolate; 400 friend class TimeLog; 401 friend class Profiler; 402 template <StateTag Tag> friend class VMState; 403 friend class LoggerTestHelper; 404 405 bool is_logging_; 406 Log* log_; 407 PerfBasicLogger* perf_basic_logger_; 408 PerfJitLogger* perf_jit_logger_; 409 LowLevelLogger* ll_logger_; 410 JitLogger* jit_logger_; 411 List<CodeEventListener*> listeners_; 412 413 // Guards against multiple calls to TearDown() that can happen in some tests. 414 // 'true' between SetUp() and TearDown(). 415 bool is_initialized_; 416 417 base::ElapsedTimer timer_; 418 419 friend class CpuProfiler; 420 }; 421 422 423 #define TIMER_EVENTS_LIST(V) \ 424 V(RecompileSynchronous, true) \ 425 V(RecompileConcurrent, true) \ 426 V(CompileFullCode, true) \ 427 V(Execute, true) \ 428 V(External, true) \ 429 V(IcMiss, false) 430 431 #define V(TimerName, expose) \ 432 class TimerEvent##TimerName : public AllStatic { \ 433 public: \ 434 static const char* name(void* unused = NULL) { return "V8." #TimerName; } \ 435 static bool expose_to_api() { return expose; } \ 436 }; 437 TIMER_EVENTS_LIST(V) 438 #undef V 439 440 441 template <class TimerEvent> 442 class TimerEventScope { 443 public: 444 explicit TimerEventScope(Isolate* isolate) : isolate_(isolate) { 445 LogTimerEvent(Logger::START); 446 } 447 448 ~TimerEventScope() { LogTimerEvent(Logger::END); } 449 450 void LogTimerEvent(Logger::StartEnd se); 451 452 private: 453 Isolate* isolate_; 454 }; 455 456 457 class CodeEventListener { 458 public: 459 virtual ~CodeEventListener() {} 460 461 virtual void CodeCreateEvent(Logger::LogEventsAndTags tag, 462 Code* code, 463 const char* comment) = 0; 464 virtual void CodeCreateEvent(Logger::LogEventsAndTags tag, 465 Code* code, 466 Name* name) = 0; 467 virtual void CodeCreateEvent(Logger::LogEventsAndTags tag, 468 Code* code, 469 SharedFunctionInfo* shared, 470 CompilationInfo* info, 471 Name* name) = 0; 472 virtual void CodeCreateEvent(Logger::LogEventsAndTags tag, 473 Code* code, 474 SharedFunctionInfo* shared, 475 CompilationInfo* info, 476 Name* source, 477 int line, int column) = 0; 478 virtual void CodeCreateEvent(Logger::LogEventsAndTags tag, 479 Code* code, 480 int args_count) = 0; 481 virtual void CallbackEvent(Name* name, Address entry_point) = 0; 482 virtual void GetterCallbackEvent(Name* name, Address entry_point) = 0; 483 virtual void SetterCallbackEvent(Name* name, Address entry_point) = 0; 484 virtual void RegExpCodeCreateEvent(Code* code, String* source) = 0; 485 virtual void CodeMoveEvent(Address from, Address to) = 0; 486 virtual void CodeDeleteEvent(Address from) = 0; 487 virtual void SharedFunctionInfoMoveEvent(Address from, Address to) = 0; 488 virtual void CodeMovingGCEvent() = 0; 489 virtual void CodeDisableOptEvent(Code* code, SharedFunctionInfo* shared) = 0; 490 }; 491 492 493 class CodeEventLogger : public CodeEventListener { 494 public: 495 CodeEventLogger(); 496 virtual ~CodeEventLogger(); 497 498 virtual void CodeCreateEvent(Logger::LogEventsAndTags tag, 499 Code* code, 500 const char* comment); 501 virtual void CodeCreateEvent(Logger::LogEventsAndTags tag, 502 Code* code, 503 Name* name); 504 virtual void CodeCreateEvent(Logger::LogEventsAndTags tag, 505 Code* code, 506 int args_count); 507 virtual void CodeCreateEvent(Logger::LogEventsAndTags tag, 508 Code* code, 509 SharedFunctionInfo* shared, 510 CompilationInfo* info, 511 Name* name); 512 virtual void CodeCreateEvent(Logger::LogEventsAndTags tag, 513 Code* code, 514 SharedFunctionInfo* shared, 515 CompilationInfo* info, 516 Name* source, 517 int line, int column); 518 virtual void RegExpCodeCreateEvent(Code* code, String* source); 519 520 virtual void CallbackEvent(Name* name, Address entry_point) { } 521 virtual void GetterCallbackEvent(Name* name, Address entry_point) { } 522 virtual void SetterCallbackEvent(Name* name, Address entry_point) { } 523 virtual void SharedFunctionInfoMoveEvent(Address from, Address to) { } 524 virtual void CodeMovingGCEvent() { } 525 526 private: 527 class NameBuffer; 528 529 virtual void LogRecordedBuffer(Code* code, 530 SharedFunctionInfo* shared, 531 const char* name, 532 int length) = 0; 533 534 NameBuffer* name_buffer_; 535 }; 536 537 538 } } // namespace v8::internal 539 540 541 #endif // V8_LOG_H_ 542
