OLD | NEW |
1 // Copyright 2009 the V8 project authors. All rights reserved. | 1 // Copyright 2009 the V8 project authors. All rights reserved. |
2 // Redistribution and use in source and binary forms, with or without | 2 // Redistribution and use in source and binary forms, with or without |
3 // modification, are permitted provided that the following conditions are | 3 // modification, are permitted provided that the following conditions are |
4 // met: | 4 // met: |
5 // | 5 // |
6 // * Redistributions of source code must retain the above copyright | 6 // * Redistributions of source code must retain the above copyright |
7 // notice, this list of conditions and the following disclaimer. | 7 // notice, this list of conditions and the following disclaimer. |
8 // * Redistributions in binary form must reproduce the above | 8 // * Redistributions in binary form must reproduce the above |
9 // copyright notice, this list of conditions and the following | 9 // copyright notice, this list of conditions and the following |
10 // disclaimer in the documentation and/or other materials provided | 10 // disclaimer in the documentation and/or other materials provided |
(...skipping 316 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
327 TickSample sample; | 327 TickSample sample; |
328 bool overflow = Remove(&sample); | 328 bool overflow = Remove(&sample); |
329 i::Isolate* isolate = ISOLATE; | 329 i::Isolate* isolate = ISOLATE; |
330 while (running_) { | 330 while (running_) { |
331 LOG(isolate, TickEvent(&sample, overflow)); | 331 LOG(isolate, TickEvent(&sample, overflow)); |
332 overflow = Remove(&sample); | 332 overflow = Remove(&sample); |
333 } | 333 } |
334 } | 334 } |
335 | 335 |
336 | 336 |
| 337 // Low-level profiling event structures. |
| 338 |
| 339 struct LowLevelCodeCreateStruct { |
| 340 static const char kTag = 'C'; |
| 341 |
| 342 int32_t name_size; |
| 343 Address code_address; |
| 344 int32_t code_size; |
| 345 }; |
| 346 |
| 347 |
| 348 struct LowLevelCodeMoveStruct { |
| 349 static const char kTag = 'M'; |
| 350 |
| 351 Address from_address; |
| 352 Address to_address; |
| 353 }; |
| 354 |
| 355 |
| 356 struct LowLevelCodeDeleteStruct { |
| 357 static const char kTag = 'D'; |
| 358 |
| 359 Address address; |
| 360 }; |
| 361 |
| 362 |
| 363 struct LowLevelSnapshotPositionStruct { |
| 364 static const char kTag = 'P'; |
| 365 |
| 366 Address address; |
| 367 int32_t position; |
| 368 }; |
| 369 |
| 370 |
| 371 static const char kCodeMovingGCTag = 'G'; |
| 372 |
| 373 |
337 // | 374 // |
338 // Logger class implementation. | 375 // Logger class implementation. |
339 // | 376 // |
340 | 377 |
| 378 class Logger::NameMap { |
| 379 public: |
| 380 NameMap() : impl_(&PointerEquals) {} |
| 381 |
| 382 ~NameMap() { |
| 383 for (HashMap::Entry* p = impl_.Start(); p != NULL; p = impl_.Next(p)) { |
| 384 DeleteArray(static_cast<const char*>(p->value)); |
| 385 } |
| 386 } |
| 387 |
| 388 void Insert(Address code_address, const char* name, int name_size) { |
| 389 HashMap::Entry* entry = FindOrCreateEntry(code_address); |
| 390 if (entry->value == NULL) { |
| 391 entry->value = CopyName(name, name_size); |
| 392 } |
| 393 } |
| 394 |
| 395 const char* Lookup(Address code_address) { |
| 396 HashMap::Entry* entry = FindEntry(code_address); |
| 397 return (entry != NULL) ? static_cast<const char*>(entry->value) : NULL; |
| 398 } |
| 399 |
| 400 void Remove(Address code_address) { |
| 401 HashMap::Entry* entry = FindEntry(code_address); |
| 402 if (entry != NULL) DeleteArray(static_cast<const char*>(entry->value)); |
| 403 RemoveEntry(entry); |
| 404 } |
| 405 |
| 406 void Move(Address from, Address to) { |
| 407 if (from == to) return; |
| 408 HashMap::Entry* from_entry = FindEntry(from); |
| 409 ASSERT(from_entry != NULL); |
| 410 void* value = from_entry->value; |
| 411 RemoveEntry(from_entry); |
| 412 HashMap::Entry* to_entry = FindOrCreateEntry(to); |
| 413 ASSERT(to_entry->value == NULL); |
| 414 to_entry->value = value; |
| 415 } |
| 416 |
| 417 private: |
| 418 static bool PointerEquals(void* lhs, void* rhs) { |
| 419 return lhs == rhs; |
| 420 } |
| 421 |
| 422 static char* CopyName(const char* name, int name_size) { |
| 423 char* result = NewArray<char>(name_size + 1); |
| 424 for (int i = 0; i < name_size; ++i) { |
| 425 char c = name[i]; |
| 426 if (c == '\0') c = ' '; |
| 427 result[i] = c; |
| 428 } |
| 429 result[name_size] = '\0'; |
| 430 return result; |
| 431 } |
| 432 |
| 433 HashMap::Entry* FindOrCreateEntry(Address code_address) { |
| 434 return impl_.Lookup(code_address, ComputePointerHash(code_address), true); |
| 435 } |
| 436 |
| 437 HashMap::Entry* FindEntry(Address code_address) { |
| 438 return impl_.Lookup(code_address, ComputePointerHash(code_address), false); |
| 439 } |
| 440 |
| 441 void RemoveEntry(HashMap::Entry* entry) { |
| 442 impl_.Remove(entry->key, entry->hash); |
| 443 } |
| 444 |
| 445 HashMap impl_; |
| 446 |
| 447 DISALLOW_COPY_AND_ASSIGN(NameMap); |
| 448 }; |
| 449 |
| 450 |
| 451 class Logger::NameBuffer { |
| 452 public: |
| 453 NameBuffer() { Reset(); } |
| 454 |
| 455 void Reset() { |
| 456 utf8_pos_ = 0; |
| 457 } |
| 458 |
| 459 void AppendString(String* str) { |
| 460 if (str == NULL) return; |
| 461 if (str->HasOnlyAsciiChars()) { |
| 462 int utf8_length = Min(str->length(), kUtf8BufferSize - utf8_pos_); |
| 463 String::WriteToFlat(str, utf8_buffer_ + utf8_pos_, 0, utf8_length); |
| 464 utf8_pos_ += utf8_length; |
| 465 return; |
| 466 } |
| 467 int uc16_length = Min(str->length(), kUc16BufferSize); |
| 468 String::WriteToFlat(str, uc16_buffer_, 0, uc16_length); |
| 469 for (int i = 0; i < uc16_length && utf8_pos_ < kUtf8BufferSize; ++i) { |
| 470 uc16 c = uc16_buffer_[i]; |
| 471 if (c <= String::kMaxAsciiCharCodeU) { |
| 472 utf8_buffer_[utf8_pos_++] = c; |
| 473 } else { |
| 474 int char_length = unibrow::Utf8::Length(c); |
| 475 if (utf8_pos_ + char_length > kUtf8BufferSize) break; |
| 476 unibrow::Utf8::Encode(utf8_buffer_ + utf8_pos_, c); |
| 477 utf8_pos_ += char_length; |
| 478 } |
| 479 } |
| 480 } |
| 481 |
| 482 void AppendBytes(const char* bytes, int size) { |
| 483 size = Min(size, kUtf8BufferSize - utf8_pos_); |
| 484 memcpy(utf8_buffer_ + utf8_pos_, bytes, size); |
| 485 utf8_pos_ += size; |
| 486 } |
| 487 |
| 488 void AppendBytes(const char* bytes) { |
| 489 AppendBytes(bytes, StrLength(bytes)); |
| 490 } |
| 491 |
| 492 void AppendByte(char c) { |
| 493 if (utf8_pos_ >= kUtf8BufferSize) return; |
| 494 utf8_buffer_[utf8_pos_++] = c; |
| 495 } |
| 496 |
| 497 void AppendInt(int n) { |
| 498 Vector<char> buffer(utf8_buffer_ + utf8_pos_, kUtf8BufferSize - utf8_pos_); |
| 499 int size = OS::SNPrintF(buffer, "%d", n); |
| 500 if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) { |
| 501 utf8_pos_ += size; |
| 502 } |
| 503 } |
| 504 |
| 505 const char* get() { return utf8_buffer_; } |
| 506 int size() const { return utf8_pos_; } |
| 507 |
| 508 private: |
| 509 static const int kUtf8BufferSize = 512; |
| 510 static const int kUc16BufferSize = 128; |
| 511 |
| 512 int utf8_pos_; |
| 513 char utf8_buffer_[kUtf8BufferSize]; |
| 514 uc16 uc16_buffer_[kUc16BufferSize]; |
| 515 }; |
| 516 |
| 517 |
341 Logger::Logger() | 518 Logger::Logger() |
342 : ticker_(NULL), | 519 : ticker_(NULL), |
343 profiler_(NULL), | 520 profiler_(NULL), |
344 sliding_state_window_(NULL), | 521 sliding_state_window_(NULL), |
345 log_events_(NULL), | 522 log_events_(NULL), |
346 logging_nesting_(0), | 523 logging_nesting_(0), |
347 cpu_profiler_nesting_(0), | 524 cpu_profiler_nesting_(0), |
348 heap_profiler_nesting_(0), | 525 heap_profiler_nesting_(0), |
349 log_(new Log(this)), | 526 log_(new Log(this)), |
| 527 name_buffer_(new NameBuffer), |
| 528 address_to_name_map_(NULL), |
350 is_initialized_(false), | 529 is_initialized_(false), |
351 last_address_(NULL), | 530 last_address_(NULL), |
352 prev_sp_(NULL), | 531 prev_sp_(NULL), |
353 prev_function_(NULL), | 532 prev_function_(NULL), |
354 prev_to_(NULL), | 533 prev_to_(NULL), |
355 prev_code_(NULL) { | 534 prev_code_(NULL) { |
356 } | 535 } |
357 | 536 |
| 537 |
358 Logger::~Logger() { | 538 Logger::~Logger() { |
| 539 delete address_to_name_map_; |
| 540 delete name_buffer_; |
359 delete log_; | 541 delete log_; |
360 } | 542 } |
361 | 543 |
| 544 |
362 #define DECLARE_EVENT(ignore1, name) name, | 545 #define DECLARE_EVENT(ignore1, name) name, |
363 static const char* const kLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = { | 546 static const char* const kLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = { |
364 LOG_EVENTS_AND_TAGS_LIST(DECLARE_EVENT) | 547 LOG_EVENTS_AND_TAGS_LIST(DECLARE_EVENT) |
365 }; | 548 }; |
366 #undef DECLARE_EVENT | 549 #undef DECLARE_EVENT |
367 | 550 |
368 | 551 |
369 void Logger::ProfilerBeginEvent() { | 552 void Logger::ProfilerBeginEvent() { |
370 if (!log_->IsEnabled()) return; | 553 if (!log_->IsEnabled()) return; |
371 LogMessageBuilder msg(this); | 554 LogMessageBuilder msg(this); |
(...skipping 356 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
728 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 911 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); |
729 CallbackEventInternal("set ", *str, entry_point); | 912 CallbackEventInternal("set ", *str, entry_point); |
730 #endif | 913 #endif |
731 } | 914 } |
732 | 915 |
733 | 916 |
734 void Logger::CodeCreateEvent(LogEventsAndTags tag, | 917 void Logger::CodeCreateEvent(LogEventsAndTags tag, |
735 Code* code, | 918 Code* code, |
736 const char* comment) { | 919 const char* comment) { |
737 #ifdef ENABLE_LOGGING_AND_PROFILING | 920 #ifdef ENABLE_LOGGING_AND_PROFILING |
738 if (!log_->IsEnabled() || !FLAG_log_code) return; | 921 if (!log_->IsEnabled()) return; |
| 922 if (FLAG_ll_prof || Serializer::enabled()) { |
| 923 name_buffer_->Reset(); |
| 924 name_buffer_->AppendBytes(kLogEventsNames[tag]); |
| 925 name_buffer_->AppendByte(':'); |
| 926 name_buffer_->AppendBytes(comment); |
| 927 } |
| 928 if (FLAG_ll_prof) { |
| 929 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size()); |
| 930 } |
| 931 if (Serializer::enabled()) { |
| 932 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size()); |
| 933 } |
| 934 if (!FLAG_log_code) return; |
739 LogMessageBuilder msg(this); | 935 LogMessageBuilder msg(this); |
740 msg.Append("%s,%s,", | 936 msg.Append("%s,%s,", |
741 kLogEventsNames[CODE_CREATION_EVENT], | 937 kLogEventsNames[CODE_CREATION_EVENT], |
742 kLogEventsNames[tag]); | 938 kLogEventsNames[tag]); |
743 msg.AppendAddress(code->address()); | 939 msg.AppendAddress(code->address()); |
744 msg.Append(",%d,\"", code->ExecutableSize()); | 940 msg.Append(",%d,\"", code->ExecutableSize()); |
745 for (const char* p = comment; *p != '\0'; p++) { | 941 for (const char* p = comment; *p != '\0'; p++) { |
746 if (*p == '"') { | 942 if (*p == '"') { |
747 msg.Append('\\'); | 943 msg.Append('\\'); |
748 } | 944 } |
749 msg.Append(*p); | 945 msg.Append(*p); |
750 } | 946 } |
751 msg.Append('"'); | 947 msg.Append('"'); |
752 LowLevelCodeCreateEvent(code, &msg); | |
753 msg.Append('\n'); | 948 msg.Append('\n'); |
754 msg.WriteToLogFile(); | 949 msg.WriteToLogFile(); |
755 #endif | 950 #endif |
756 } | 951 } |
757 | 952 |
758 | 953 |
759 void Logger::CodeCreateEvent(LogEventsAndTags tag, | 954 void Logger::CodeCreateEvent(LogEventsAndTags tag, |
760 Code* code, | 955 Code* code, |
761 String* name) { | 956 String* name) { |
762 #ifdef ENABLE_LOGGING_AND_PROFILING | 957 #ifdef ENABLE_LOGGING_AND_PROFILING |
763 if (name != NULL) { | 958 if (!log_->IsEnabled()) return; |
764 SmartPointer<char> str = | 959 if (FLAG_ll_prof || Serializer::enabled()) { |
765 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 960 name_buffer_->Reset(); |
766 CodeCreateEvent(tag, code, *str); | 961 name_buffer_->AppendBytes(kLogEventsNames[tag]); |
767 } else { | 962 name_buffer_->AppendByte(':'); |
768 CodeCreateEvent(tag, code, ""); | 963 name_buffer_->AppendString(name); |
769 } | 964 } |
| 965 if (FLAG_ll_prof) { |
| 966 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size()); |
| 967 } |
| 968 if (Serializer::enabled()) { |
| 969 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size()); |
| 970 } |
| 971 if (!FLAG_log_code) return; |
| 972 LogMessageBuilder msg(this); |
| 973 msg.Append("%s,%s,", |
| 974 kLogEventsNames[CODE_CREATION_EVENT], |
| 975 kLogEventsNames[tag]); |
| 976 msg.AppendAddress(code->address()); |
| 977 msg.Append(",%d,\"", code->ExecutableSize()); |
| 978 msg.AppendDetailed(name, false); |
| 979 msg.Append('"'); |
| 980 msg.Append('\n'); |
| 981 msg.WriteToLogFile(); |
770 #endif | 982 #endif |
771 } | 983 } |
772 | 984 |
773 | 985 |
774 #ifdef ENABLE_LOGGING_AND_PROFILING | 986 #ifdef ENABLE_LOGGING_AND_PROFILING |
775 // ComputeMarker must only be used when SharedFunctionInfo is known. | 987 // ComputeMarker must only be used when SharedFunctionInfo is known. |
776 static const char* ComputeMarker(Code* code) { | 988 static const char* ComputeMarker(Code* code) { |
777 switch (code->kind()) { | 989 switch (code->kind()) { |
778 case Code::FUNCTION: return code->optimizable() ? "~" : ""; | 990 case Code::FUNCTION: return code->optimizable() ? "~" : ""; |
779 case Code::OPTIMIZED_FUNCTION: return "*"; | 991 case Code::OPTIMIZED_FUNCTION: return "*"; |
780 default: return ""; | 992 default: return ""; |
781 } | 993 } |
782 } | 994 } |
783 #endif | 995 #endif |
784 | 996 |
785 | 997 |
786 void Logger::CodeCreateEvent(LogEventsAndTags tag, | 998 void Logger::CodeCreateEvent(LogEventsAndTags tag, |
787 Code* code, | 999 Code* code, |
788 SharedFunctionInfo* shared, | 1000 SharedFunctionInfo* shared, |
789 String* name) { | 1001 String* name) { |
790 #ifdef ENABLE_LOGGING_AND_PROFILING | 1002 #ifdef ENABLE_LOGGING_AND_PROFILING |
791 if (!log_->IsEnabled() || !FLAG_log_code) return; | 1003 if (!log_->IsEnabled()) return; |
| 1004 if (FLAG_ll_prof || Serializer::enabled()) { |
| 1005 name_buffer_->Reset(); |
| 1006 name_buffer_->AppendBytes(kLogEventsNames[tag]); |
| 1007 name_buffer_->AppendByte(':'); |
| 1008 name_buffer_->AppendString(name); |
| 1009 } |
| 1010 if (FLAG_ll_prof) { |
| 1011 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size()); |
| 1012 } |
| 1013 if (Serializer::enabled()) { |
| 1014 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size()); |
| 1015 } |
| 1016 if (!FLAG_log_code) return; |
792 if (code == Isolate::Current()->builtins()->builtin( | 1017 if (code == Isolate::Current()->builtins()->builtin( |
793 Builtins::kLazyCompile)) | 1018 Builtins::kLazyCompile)) |
794 return; | 1019 return; |
795 | 1020 |
796 LogMessageBuilder msg(this); | 1021 LogMessageBuilder msg(this); |
797 SmartPointer<char> str = | 1022 SmartPointer<char> str = |
798 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 1023 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); |
799 msg.Append("%s,%s,", | 1024 msg.Append("%s,%s,", |
800 kLogEventsNames[CODE_CREATION_EVENT], | 1025 kLogEventsNames[CODE_CREATION_EVENT], |
801 kLogEventsNames[tag]); | 1026 kLogEventsNames[tag]); |
802 msg.AppendAddress(code->address()); | 1027 msg.AppendAddress(code->address()); |
803 msg.Append(",%d,\"%s\",", code->ExecutableSize(), *str); | 1028 msg.Append(",%d,\"%s\",", code->ExecutableSize(), *str); |
804 msg.AppendAddress(shared->address()); | 1029 msg.AppendAddress(shared->address()); |
805 msg.Append(",%s", ComputeMarker(code)); | 1030 msg.Append(",%s", ComputeMarker(code)); |
806 LowLevelCodeCreateEvent(code, &msg); | |
807 msg.Append('\n'); | 1031 msg.Append('\n'); |
808 msg.WriteToLogFile(); | 1032 msg.WriteToLogFile(); |
809 #endif | 1033 #endif |
810 } | 1034 } |
811 | 1035 |
812 | 1036 |
813 // Although, it is possible to extract source and line from | 1037 // Although, it is possible to extract source and line from |
814 // the SharedFunctionInfo object, we left it to caller | 1038 // the SharedFunctionInfo object, we left it to caller |
815 // to leave logging functions free from heap allocations. | 1039 // to leave logging functions free from heap allocations. |
816 void Logger::CodeCreateEvent(LogEventsAndTags tag, | 1040 void Logger::CodeCreateEvent(LogEventsAndTags tag, |
817 Code* code, | 1041 Code* code, |
818 SharedFunctionInfo* shared, | 1042 SharedFunctionInfo* shared, |
819 String* source, int line) { | 1043 String* source, int line) { |
820 #ifdef ENABLE_LOGGING_AND_PROFILING | 1044 #ifdef ENABLE_LOGGING_AND_PROFILING |
821 if (!log_->IsEnabled() || !FLAG_log_code) return; | 1045 if (!log_->IsEnabled()) return; |
| 1046 if (FLAG_ll_prof || Serializer::enabled()) { |
| 1047 name_buffer_->Reset(); |
| 1048 name_buffer_->AppendBytes(kLogEventsNames[tag]); |
| 1049 name_buffer_->AppendByte(':'); |
| 1050 name_buffer_->AppendString(shared->DebugName()); |
| 1051 name_buffer_->AppendByte(' '); |
| 1052 name_buffer_->AppendString(source); |
| 1053 name_buffer_->AppendByte(':'); |
| 1054 name_buffer_->AppendInt(line); |
| 1055 } |
| 1056 if (FLAG_ll_prof) { |
| 1057 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size()); |
| 1058 } |
| 1059 if (Serializer::enabled()) { |
| 1060 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size()); |
| 1061 } |
| 1062 if (!FLAG_log_code) return; |
822 LogMessageBuilder msg(this); | 1063 LogMessageBuilder msg(this); |
823 SmartPointer<char> name = | 1064 SmartPointer<char> name = |
824 shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 1065 shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); |
825 SmartPointer<char> sourcestr = | 1066 SmartPointer<char> sourcestr = |
826 source->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); | 1067 source->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); |
827 msg.Append("%s,%s,", | 1068 msg.Append("%s,%s,", |
828 kLogEventsNames[CODE_CREATION_EVENT], | 1069 kLogEventsNames[CODE_CREATION_EVENT], |
829 kLogEventsNames[tag]); | 1070 kLogEventsNames[tag]); |
830 msg.AppendAddress(code->address()); | 1071 msg.AppendAddress(code->address()); |
831 msg.Append(",%d,\"%s %s:%d\",", | 1072 msg.Append(",%d,\"%s %s:%d\",", |
832 code->ExecutableSize(), | 1073 code->ExecutableSize(), |
833 *name, | 1074 *name, |
834 *sourcestr, | 1075 *sourcestr, |
835 line); | 1076 line); |
836 msg.AppendAddress(shared->address()); | 1077 msg.AppendAddress(shared->address()); |
837 msg.Append(",%s", ComputeMarker(code)); | 1078 msg.Append(",%s", ComputeMarker(code)); |
838 LowLevelCodeCreateEvent(code, &msg); | |
839 msg.Append('\n'); | 1079 msg.Append('\n'); |
840 msg.WriteToLogFile(); | 1080 msg.WriteToLogFile(); |
841 #endif | 1081 #endif |
842 } | 1082 } |
843 | 1083 |
844 | 1084 |
845 void Logger::CodeCreateEvent(LogEventsAndTags tag, Code* code, int args_count) { | 1085 void Logger::CodeCreateEvent(LogEventsAndTags tag, Code* code, int args_count) { |
846 #ifdef ENABLE_LOGGING_AND_PROFILING | 1086 #ifdef ENABLE_LOGGING_AND_PROFILING |
847 if (!log_->IsEnabled() || !FLAG_log_code) return; | 1087 if (!log_->IsEnabled()) return; |
| 1088 if (FLAG_ll_prof || Serializer::enabled()) { |
| 1089 name_buffer_->Reset(); |
| 1090 name_buffer_->AppendBytes(kLogEventsNames[tag]); |
| 1091 name_buffer_->AppendByte(':'); |
| 1092 name_buffer_->AppendInt(args_count); |
| 1093 } |
| 1094 if (FLAG_ll_prof) { |
| 1095 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size()); |
| 1096 } |
| 1097 if (Serializer::enabled()) { |
| 1098 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size()); |
| 1099 } |
| 1100 if (!FLAG_log_code) return; |
848 LogMessageBuilder msg(this); | 1101 LogMessageBuilder msg(this); |
849 msg.Append("%s,%s,", | 1102 msg.Append("%s,%s,", |
850 kLogEventsNames[CODE_CREATION_EVENT], | 1103 kLogEventsNames[CODE_CREATION_EVENT], |
851 kLogEventsNames[tag]); | 1104 kLogEventsNames[tag]); |
852 msg.AppendAddress(code->address()); | 1105 msg.AppendAddress(code->address()); |
853 msg.Append(",%d,\"args_count: %d\"", code->ExecutableSize(), args_count); | 1106 msg.Append(",%d,\"args_count: %d\"", code->ExecutableSize(), args_count); |
854 LowLevelCodeCreateEvent(code, &msg); | |
855 msg.Append('\n'); | 1107 msg.Append('\n'); |
856 msg.WriteToLogFile(); | 1108 msg.WriteToLogFile(); |
857 #endif | 1109 #endif |
858 } | 1110 } |
859 | 1111 |
860 | 1112 |
861 void Logger::CodeMovingGCEvent() { | 1113 void Logger::CodeMovingGCEvent() { |
862 #ifdef ENABLE_LOGGING_AND_PROFILING | 1114 #ifdef ENABLE_LOGGING_AND_PROFILING |
863 if (!log_->IsEnabled() || !FLAG_log_code || !FLAG_ll_prof) return; | 1115 if (!log_->IsEnabled() || !FLAG_ll_prof) return; |
864 LogMessageBuilder msg(this); | 1116 LowLevelLogWriteBytes(&kCodeMovingGCTag, sizeof(kCodeMovingGCTag)); |
865 msg.Append("%s\n", kLogEventsNames[CODE_MOVING_GC]); | |
866 msg.WriteToLogFile(); | |
867 OS::SignalCodeMovingGC(); | 1117 OS::SignalCodeMovingGC(); |
868 #endif | 1118 #endif |
869 } | 1119 } |
870 | 1120 |
871 | 1121 |
872 void Logger::RegExpCodeCreateEvent(Code* code, String* source) { | 1122 void Logger::RegExpCodeCreateEvent(Code* code, String* source) { |
873 #ifdef ENABLE_LOGGING_AND_PROFILING | 1123 #ifdef ENABLE_LOGGING_AND_PROFILING |
874 if (!log_->IsEnabled() || !FLAG_log_code) return; | 1124 if (!log_->IsEnabled()) return; |
| 1125 if (FLAG_ll_prof || Serializer::enabled()) { |
| 1126 name_buffer_->Reset(); |
| 1127 name_buffer_->AppendBytes(kLogEventsNames[REG_EXP_TAG]); |
| 1128 name_buffer_->AppendByte(':'); |
| 1129 name_buffer_->AppendString(source); |
| 1130 } |
| 1131 if (FLAG_ll_prof) { |
| 1132 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size()); |
| 1133 } |
| 1134 if (Serializer::enabled()) { |
| 1135 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size()); |
| 1136 } |
| 1137 if (!FLAG_log_code) return; |
875 LogMessageBuilder msg(this); | 1138 LogMessageBuilder msg(this); |
876 msg.Append("%s,%s,", | 1139 msg.Append("%s,%s,", |
877 kLogEventsNames[CODE_CREATION_EVENT], | 1140 kLogEventsNames[CODE_CREATION_EVENT], |
878 kLogEventsNames[REG_EXP_TAG]); | 1141 kLogEventsNames[REG_EXP_TAG]); |
879 msg.AppendAddress(code->address()); | 1142 msg.AppendAddress(code->address()); |
880 msg.Append(",%d,\"", code->ExecutableSize()); | 1143 msg.Append(",%d,\"", code->ExecutableSize()); |
881 msg.AppendDetailed(source, false); | 1144 msg.AppendDetailed(source, false); |
882 msg.Append('\"'); | 1145 msg.Append('\"'); |
883 LowLevelCodeCreateEvent(code, &msg); | |
884 msg.Append('\n'); | 1146 msg.Append('\n'); |
885 msg.WriteToLogFile(); | 1147 msg.WriteToLogFile(); |
886 #endif | 1148 #endif |
887 } | 1149 } |
888 | 1150 |
889 | 1151 |
890 void Logger::CodeMoveEvent(Address from, Address to) { | 1152 void Logger::CodeMoveEvent(Address from, Address to) { |
891 #ifdef ENABLE_LOGGING_AND_PROFILING | 1153 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 1154 if (!log_->IsEnabled()) return; |
| 1155 if (FLAG_ll_prof) LowLevelCodeMoveEvent(from, to); |
| 1156 if (Serializer::enabled() && address_to_name_map_ != NULL) { |
| 1157 address_to_name_map_->Move(from, to); |
| 1158 } |
892 MoveEventInternal(CODE_MOVE_EVENT, from, to); | 1159 MoveEventInternal(CODE_MOVE_EVENT, from, to); |
893 #endif | 1160 #endif |
894 } | 1161 } |
895 | 1162 |
896 | 1163 |
897 void Logger::CodeDeleteEvent(Address from) { | 1164 void Logger::CodeDeleteEvent(Address from) { |
898 #ifdef ENABLE_LOGGING_AND_PROFILING | 1165 #ifdef ENABLE_LOGGING_AND_PROFILING |
| 1166 if (!log_->IsEnabled()) return; |
| 1167 if (FLAG_ll_prof) LowLevelCodeDeleteEvent(from); |
| 1168 if (Serializer::enabled() && address_to_name_map_ != NULL) { |
| 1169 address_to_name_map_->Remove(from); |
| 1170 } |
899 DeleteEventInternal(CODE_DELETE_EVENT, from); | 1171 DeleteEventInternal(CODE_DELETE_EVENT, from); |
900 #endif | 1172 #endif |
901 } | 1173 } |
902 | 1174 |
903 | 1175 |
904 void Logger::SnapshotPositionEvent(Address addr, int pos) { | 1176 void Logger::SnapshotPositionEvent(Address addr, int pos) { |
905 #ifdef ENABLE_LOGGING_AND_PROFILING | 1177 #ifdef ENABLE_LOGGING_AND_PROFILING |
906 if (!log_->IsEnabled() || !FLAG_log_snapshot_positions) return; | 1178 if (!log_->IsEnabled()) return; |
| 1179 if (FLAG_ll_prof) LowLevelSnapshotPositionEvent(addr, pos); |
| 1180 if (Serializer::enabled() && address_to_name_map_ != NULL) { |
| 1181 const char* code_name = address_to_name_map_->Lookup(addr); |
| 1182 if (code_name == NULL) return; // Not a code object. |
| 1183 LogMessageBuilder msg(this); |
| 1184 msg.Append("%s,%d,\"", kLogEventsNames[SNAPSHOT_CODE_NAME_EVENT], pos); |
| 1185 for (const char* p = code_name; *p != '\0'; ++p) { |
| 1186 if (*p == '"') msg.Append('\\'); |
| 1187 msg.Append(*p); |
| 1188 } |
| 1189 msg.Append("\"\n"); |
| 1190 msg.WriteToLogFile(); |
| 1191 } |
| 1192 if (!FLAG_log_snapshot_positions) return; |
907 LogMessageBuilder msg(this); | 1193 LogMessageBuilder msg(this); |
908 msg.Append("%s,", kLogEventsNames[SNAPSHOT_POSITION_EVENT]); | 1194 msg.Append("%s,", kLogEventsNames[SNAPSHOT_POSITION_EVENT]); |
909 msg.AppendAddress(addr); | 1195 msg.AppendAddress(addr); |
910 msg.Append(",%d", pos); | 1196 msg.Append(",%d", pos); |
911 msg.Append('\n'); | 1197 msg.Append('\n'); |
912 msg.WriteToLogFile(); | 1198 msg.WriteToLogFile(); |
913 #endif | 1199 #endif |
914 } | 1200 } |
915 | 1201 |
916 | 1202 |
(...skipping 384 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1301 EnumerateOptimizedFunctionsVisitor visitor(sfis, | 1587 EnumerateOptimizedFunctionsVisitor visitor(sfis, |
1302 code_objects, | 1588 code_objects, |
1303 &compiled_funcs_count); | 1589 &compiled_funcs_count); |
1304 Deoptimizer::VisitAllOptimizedFunctions(&visitor); | 1590 Deoptimizer::VisitAllOptimizedFunctions(&visitor); |
1305 | 1591 |
1306 return compiled_funcs_count; | 1592 return compiled_funcs_count; |
1307 } | 1593 } |
1308 | 1594 |
1309 | 1595 |
1310 void Logger::LogCodeObject(Object* object) { | 1596 void Logger::LogCodeObject(Object* object) { |
1311 if (FLAG_log_code) { | 1597 if (FLAG_log_code || FLAG_ll_prof) { |
1312 Code* code_object = Code::cast(object); | 1598 Code* code_object = Code::cast(object); |
1313 LogEventsAndTags tag = Logger::STUB_TAG; | 1599 LogEventsAndTags tag = Logger::STUB_TAG; |
1314 const char* description = "Unknown code from the snapshot"; | 1600 const char* description = "Unknown code from the snapshot"; |
1315 switch (code_object->kind()) { | 1601 switch (code_object->kind()) { |
1316 case Code::FUNCTION: | 1602 case Code::FUNCTION: |
1317 case Code::OPTIMIZED_FUNCTION: | 1603 case Code::OPTIMIZED_FUNCTION: |
1318 return; // We log this later using LogCompiledFunctions. | 1604 return; // We log this later using LogCompiledFunctions. |
1319 case Code::TYPE_RECORDING_BINARY_OP_IC: // fall through | 1605 case Code::TYPE_RECORDING_BINARY_OP_IC: // fall through |
1320 case Code::COMPARE_IC: // fall through | 1606 case Code::COMPARE_IC: // fall through |
1321 case Code::STUB: | 1607 case Code::STUB: |
(...skipping 40 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1362 tag = Logger::KEYED_CALL_IC_TAG; | 1648 tag = Logger::KEYED_CALL_IC_TAG; |
1363 break; | 1649 break; |
1364 } | 1650 } |
1365 PROFILE(ISOLATE, CodeCreateEvent(tag, code_object, description)); | 1651 PROFILE(ISOLATE, CodeCreateEvent(tag, code_object, description)); |
1366 } | 1652 } |
1367 } | 1653 } |
1368 | 1654 |
1369 | 1655 |
1370 void Logger::LogCodeInfo() { | 1656 void Logger::LogCodeInfo() { |
1371 #ifdef ENABLE_LOGGING_AND_PROFILING | 1657 #ifdef ENABLE_LOGGING_AND_PROFILING |
1372 if (!log_->IsEnabled() || !FLAG_log_code || !FLAG_ll_prof) return; | 1658 if (!log_->IsEnabled() || !FLAG_ll_prof) return; |
1373 #if V8_TARGET_ARCH_IA32 | 1659 #if V8_TARGET_ARCH_IA32 |
1374 const char arch[] = "ia32"; | 1660 const char arch[] = "ia32"; |
1375 #elif V8_TARGET_ARCH_X64 | 1661 #elif V8_TARGET_ARCH_X64 |
1376 const char arch[] = "x64"; | 1662 const char arch[] = "x64"; |
1377 #elif V8_TARGET_ARCH_ARM | 1663 #elif V8_TARGET_ARCH_ARM |
1378 const char arch[] = "arm"; | 1664 const char arch[] = "arm"; |
1379 #else | 1665 #else |
1380 const char arch[] = "unknown"; | 1666 const char arch[] = "unknown"; |
1381 #endif | 1667 #endif |
1382 LogMessageBuilder msg(this); | 1668 LowLevelLogWriteBytes(arch, sizeof(arch)); |
1383 msg.Append("code-info,%s,%d\n", arch, Code::kHeaderSize); | |
1384 msg.WriteToLogFile(); | |
1385 #endif // ENABLE_LOGGING_AND_PROFILING | 1669 #endif // ENABLE_LOGGING_AND_PROFILING |
1386 } | 1670 } |
1387 | 1671 |
1388 | 1672 |
1389 void Logger::LowLevelCodeCreateEvent(Code* code, LogMessageBuilder* msg) { | 1673 void Logger::RegisterSnapshotCodeName(Code* code, |
1390 if (!FLAG_ll_prof || log_->output_code_handle_ == NULL) return; | 1674 const char* name, |
1391 int pos = static_cast<int>(ftell(log_->output_code_handle_)); | 1675 int name_size) { |
1392 size_t rv = fwrite(code->instruction_start(), 1, code->instruction_size(), | 1676 ASSERT(Serializer::enabled()); |
1393 log_->output_code_handle_); | 1677 if (address_to_name_map_ == NULL) { |
1394 ASSERT(static_cast<size_t>(code->instruction_size()) == rv); | 1678 address_to_name_map_ = new NameMap; |
1395 USE(rv); | 1679 } |
1396 msg->Append(",%d", pos); | 1680 address_to_name_map_->Insert(code->address(), name, name_size); |
1397 } | 1681 } |
1398 | 1682 |
1399 | 1683 |
| 1684 void Logger::LowLevelCodeCreateEvent(Code* code, |
| 1685 const char* name, |
| 1686 int name_size) { |
| 1687 if (log_->ll_output_handle_ == NULL) return; |
| 1688 LowLevelCodeCreateStruct event; |
| 1689 event.name_size = name_size; |
| 1690 event.code_address = code->instruction_start(); |
| 1691 ASSERT(event.code_address == code->address() + Code::kHeaderSize); |
| 1692 event.code_size = code->instruction_size(); |
| 1693 LowLevelLogWriteStruct(event); |
| 1694 LowLevelLogWriteBytes(name, name_size); |
| 1695 LowLevelLogWriteBytes( |
| 1696 reinterpret_cast<const char*>(code->instruction_start()), |
| 1697 code->instruction_size()); |
| 1698 } |
| 1699 |
| 1700 |
| 1701 void Logger::LowLevelCodeMoveEvent(Address from, Address to) { |
| 1702 if (log_->ll_output_handle_ == NULL) return; |
| 1703 LowLevelCodeMoveStruct event; |
| 1704 event.from_address = from + Code::kHeaderSize; |
| 1705 event.to_address = to + Code::kHeaderSize; |
| 1706 LowLevelLogWriteStruct(event); |
| 1707 } |
| 1708 |
| 1709 |
| 1710 void Logger::LowLevelCodeDeleteEvent(Address from) { |
| 1711 if (log_->ll_output_handle_ == NULL) return; |
| 1712 LowLevelCodeDeleteStruct event; |
| 1713 event.address = from + Code::kHeaderSize; |
| 1714 LowLevelLogWriteStruct(event); |
| 1715 } |
| 1716 |
| 1717 |
| 1718 void Logger::LowLevelSnapshotPositionEvent(Address addr, int pos) { |
| 1719 if (log_->ll_output_handle_ == NULL) return; |
| 1720 LowLevelSnapshotPositionStruct event; |
| 1721 event.address = addr + Code::kHeaderSize; |
| 1722 event.position = pos; |
| 1723 LowLevelLogWriteStruct(event); |
| 1724 } |
| 1725 |
| 1726 |
| 1727 void Logger::LowLevelLogWriteBytes(const char* bytes, int size) { |
| 1728 size_t rv = fwrite(bytes, 1, size, log_->ll_output_handle_); |
| 1729 ASSERT(static_cast<size_t>(size) == rv); |
| 1730 USE(rv); |
| 1731 } |
| 1732 |
| 1733 |
1400 void Logger::LogCodeObjects() { | 1734 void Logger::LogCodeObjects() { |
1401 AssertNoAllocation no_alloc; | 1735 AssertNoAllocation no_alloc; |
1402 HeapIterator iterator; | 1736 HeapIterator iterator; |
1403 for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) { | 1737 for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) { |
1404 if (obj->IsCode()) LogCodeObject(obj); | 1738 if (obj->IsCode()) LogCodeObject(obj); |
1405 } | 1739 } |
1406 } | 1740 } |
1407 | 1741 |
1408 | 1742 |
1409 void Logger::LogCompiledFunctions() { | 1743 void Logger::LogCompiledFunctions() { |
(...skipping 79 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1489 | 1823 |
1490 | 1824 |
1491 bool Logger::Setup() { | 1825 bool Logger::Setup() { |
1492 #ifdef ENABLE_LOGGING_AND_PROFILING | 1826 #ifdef ENABLE_LOGGING_AND_PROFILING |
1493 // Tests and EnsureInitialize() can call this twice in a row. It's harmless. | 1827 // Tests and EnsureInitialize() can call this twice in a row. It's harmless. |
1494 if (is_initialized_) return true; | 1828 if (is_initialized_) return true; |
1495 is_initialized_ = true; | 1829 is_initialized_ = true; |
1496 | 1830 |
1497 // --ll-prof implies --log-code and --log-snapshot-positions. | 1831 // --ll-prof implies --log-code and --log-snapshot-positions. |
1498 if (FLAG_ll_prof) { | 1832 if (FLAG_ll_prof) { |
1499 FLAG_log_code = true; | |
1500 FLAG_log_snapshot_positions = true; | 1833 FLAG_log_snapshot_positions = true; |
1501 } | 1834 } |
1502 | 1835 |
1503 // --prof_lazy controls --log-code, implies --noprof_auto. | 1836 // --prof_lazy controls --log-code, implies --noprof_auto. |
1504 if (FLAG_prof_lazy) { | 1837 if (FLAG_prof_lazy) { |
1505 FLAG_log_code = false; | 1838 FLAG_log_code = false; |
1506 FLAG_prof_auto = false; | 1839 FLAG_prof_auto = false; |
1507 } | 1840 } |
1508 | 1841 |
1509 // TODO(isolates): this assert introduces cyclic dependency (logger | 1842 // TODO(isolates): this assert introduces cyclic dependency (logger |
1510 // -> thread local top -> heap -> logger). | 1843 // -> thread local top -> heap -> logger). |
1511 // ASSERT(VMState::is_outermost_external()); | 1844 // ASSERT(VMState::is_outermost_external()); |
1512 | 1845 |
1513 log_->Initialize(); | 1846 log_->Initialize(); |
1514 | 1847 |
1515 if (FLAG_ll_prof) LogCodeInfo(); | 1848 if (FLAG_ll_prof) LogCodeInfo(); |
1516 | 1849 |
1517 ticker_ = new Ticker(Isolate::Current(), kSamplingIntervalMs); | 1850 ticker_ = new Ticker(Isolate::Current(), kSamplingIntervalMs); |
1518 | 1851 |
1519 Isolate* isolate = Isolate::Current(); | 1852 Isolate* isolate = Isolate::Current(); |
1520 if (FLAG_sliding_state_window && sliding_state_window_ == NULL) { | 1853 if (FLAG_sliding_state_window && sliding_state_window_ == NULL) { |
1521 sliding_state_window_ = new SlidingStateWindow(isolate); | 1854 sliding_state_window_ = new SlidingStateWindow(isolate); |
1522 } | 1855 } |
1523 | 1856 |
1524 bool start_logging = FLAG_log || FLAG_log_runtime || FLAG_log_api | 1857 bool start_logging = FLAG_log || FLAG_log_runtime || FLAG_log_api |
1525 || FLAG_log_code || FLAG_log_gc || FLAG_log_handles || FLAG_log_suspect | 1858 || FLAG_log_code || FLAG_log_gc || FLAG_log_handles || FLAG_log_suspect |
1526 || FLAG_log_regexp || FLAG_log_state_changes; | 1859 || FLAG_log_regexp || FLAG_log_state_changes || FLAG_ll_prof; |
1527 | 1860 |
1528 if (start_logging) { | 1861 if (start_logging) { |
1529 logging_nesting_ = 1; | 1862 logging_nesting_ = 1; |
1530 } | 1863 } |
1531 | 1864 |
1532 if (FLAG_prof) { | 1865 if (FLAG_prof) { |
1533 profiler_ = new Profiler(isolate); | 1866 profiler_ = new Profiler(isolate); |
1534 if (!FLAG_prof_auto) { | 1867 if (!FLAG_prof_auto) { |
1535 profiler_->pause(); | 1868 profiler_->pause(); |
1536 } else { | 1869 } else { |
(...skipping 119 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1656 void SamplerRegistry::RemoveActiveSampler(Sampler* sampler) { | 1989 void SamplerRegistry::RemoveActiveSampler(Sampler* sampler) { |
1657 ASSERT(sampler->IsActive()); | 1990 ASSERT(sampler->IsActive()); |
1658 ScopedLock lock(mutex_); | 1991 ScopedLock lock(mutex_); |
1659 ASSERT(active_samplers_ != NULL); | 1992 ASSERT(active_samplers_ != NULL); |
1660 bool removed = active_samplers_->RemoveElement(sampler); | 1993 bool removed = active_samplers_->RemoveElement(sampler); |
1661 ASSERT(removed); | 1994 ASSERT(removed); |
1662 USE(removed); | 1995 USE(removed); |
1663 } | 1996 } |
1664 | 1997 |
1665 } } // namespace v8::internal | 1998 } } // namespace v8::internal |
OLD | NEW |