Chromium Code Reviews
chromiumcodereview-hr@appspot.gserviceaccount.com (chromiumcodereview-hr) | Please choose your nickname with Settings | Help | Chromium Project | Gerrit Changes | Sign out
(1308)

Side by Side Diff: src/log.cc

Issue 6904127: ll_prof: Reduce profiling hooks overhead from >400% to 25%. (Closed)
Patch Set: Review fixes Created 9 years, 7 months ago
Use n/p to move between diff chunks; N/P to move between comments. Draft comments are only viewable by you.
Jump to:
View unified diff | Download patch
« no previous file with comments | « src/log.h ('k') | src/log-utils.h » ('j') | no next file with comments »
Toggle Intra-line Diffs ('i') | Expand Comments ('e') | Collapse Comments ('c') | Show Comments Hide Comments ('s')
OLDNEW
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
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
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
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
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
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
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
OLDNEW
« no previous file with comments | « src/log.h ('k') | src/log-utils.h » ('j') | no next file with comments »

Powered by Google App Engine
This is Rietveld 408576698