| 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 |