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

Side by Side Diff: src/log.cc

Issue 11428025: Include more information in --prof log. (Closed) Base URL: https://v8.googlecode.com/svn/branches/bleeding_edge
Patch Set: Created 8 years 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 | Annotate | Revision Log
OLDNEW
1 // Copyright 2011 the V8 project authors. All rights reserved. 1 // Copyright 2011 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 698 matching lines...) Expand 10 before | Expand all | Expand 10 after
709 if (!log_->IsEnabled()) return; 709 if (!log_->IsEnabled()) return;
710 ASSERT(FLAG_log_timer_events); 710 ASSERT(FLAG_log_timer_events);
711 LogMessageBuilder msg(this); 711 LogMessageBuilder msg(this);
712 int since_epoch = static_cast<int>(start - epoch_); 712 int since_epoch = static_cast<int>(start - epoch_);
713 int pause_time = static_cast<int>(end - start); 713 int pause_time = static_cast<int>(end - start);
714 msg.Append("timer-event,\"%s\",%ld,%ld\n", name, since_epoch, pause_time); 714 msg.Append("timer-event,\"%s\",%ld,%ld\n", name, since_epoch, pause_time);
715 msg.WriteToLogFile(); 715 msg.WriteToLogFile();
716 } 716 }
717 717
718 718
719 void Logger::ExternalSwitch(StateTag old_tag, StateTag new_tag) {
720 if (old_tag != EXTERNAL && new_tag == EXTERNAL) {
721 enter_external_ = OS::Ticks();
722 }
723 if (old_tag == EXTERNAL && new_tag != EXTERNAL && enter_external_ != 0) {
724 TimerEvent("V8.External", enter_external_, OS::Ticks());
725 enter_external_ = 0;
726 }
727 }
728
729
730 int64_t Logger::enter_external_ = 0;
731
732
719 void Logger::TimerEventScope::LogTimerEvent() { 733 void Logger::TimerEventScope::LogTimerEvent() {
720 LOG(isolate_, TimerEvent(name_, start_, OS::Ticks())); 734 LOG(isolate_, TimerEvent(name_, start_, OS::Ticks()));
721 } 735 }
722 736
723 737
724 const char* Logger::TimerEventScope::v8_recompile_synchronous = 738 const char* Logger::TimerEventScope::v8_recompile_synchronous =
725 "V8.RecompileSynchronous"; 739 "V8.RecompileSynchronous";
726 const char* Logger::TimerEventScope::v8_recompile_parallel = 740 const char* Logger::TimerEventScope::v8_recompile_parallel =
727 "V8.RecompileParallel"; 741 "V8.RecompileParallel";
728 const char* Logger::TimerEventScope::v8_compile_full_code = 742 const char* Logger::TimerEventScope::v8_compile_full_code =
(...skipping 164 matching lines...) Expand 10 before | Expand all | Expand 10 after
893 907
894 908
895 void Logger::DeleteEventStatic(const char* name, void* object) { 909 void Logger::DeleteEventStatic(const char* name, void* object) {
896 LOGGER->DeleteEvent(name, object); 910 LOGGER->DeleteEvent(name, object);
897 } 911 }
898 912
899 void Logger::CallbackEventInternal(const char* prefix, const char* name, 913 void Logger::CallbackEventInternal(const char* prefix, const char* name,
900 Address entry_point) { 914 Address entry_point) {
901 if (!log_->IsEnabled() || !FLAG_log_code) return; 915 if (!log_->IsEnabled() || !FLAG_log_code) return;
902 LogMessageBuilder msg(this); 916 LogMessageBuilder msg(this);
903 msg.Append("%s,%s,", 917 msg.Append("%s,%s,-3,",
904 kLogEventsNames[CODE_CREATION_EVENT], 918 kLogEventsNames[CODE_CREATION_EVENT],
905 kLogEventsNames[CALLBACK_TAG]); 919 kLogEventsNames[CALLBACK_TAG]);
906 msg.AppendAddress(entry_point); 920 msg.AppendAddress(entry_point);
907 msg.Append(",1,\"%s%s\"", prefix, name); 921 msg.Append(",1,\"%s%s\"", prefix, name);
908 msg.Append('\n'); 922 msg.Append('\n');
909 msg.WriteToLogFile(); 923 msg.WriteToLogFile();
910 } 924 }
911 925
912 926
913 void Logger::CallbackEvent(String* name, Address entry_point) { 927 void Logger::CallbackEvent(String* name, Address entry_point) {
(...skipping 35 matching lines...) Expand 10 before | Expand all | Expand 10 after
949 } 963 }
950 if (!log_->IsEnabled()) return; 964 if (!log_->IsEnabled()) return;
951 if (FLAG_ll_prof) { 965 if (FLAG_ll_prof) {
952 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size()); 966 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size());
953 } 967 }
954 if (Serializer::enabled()) { 968 if (Serializer::enabled()) {
955 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size()); 969 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size());
956 } 970 }
957 if (!FLAG_log_code) return; 971 if (!FLAG_log_code) return;
958 LogMessageBuilder msg(this); 972 LogMessageBuilder msg(this);
959 msg.Append("%s,%s,", 973 msg.Append("%s,%s,%d,",
960 kLogEventsNames[CODE_CREATION_EVENT], 974 kLogEventsNames[CODE_CREATION_EVENT],
961 kLogEventsNames[tag]); 975 kLogEventsNames[tag],
976 code->kind());
962 msg.AppendAddress(code->address()); 977 msg.AppendAddress(code->address());
963 msg.Append(",%d,\"", code->ExecutableSize()); 978 msg.Append(",%d,\"", code->ExecutableSize());
964 for (const char* p = comment; *p != '\0'; p++) { 979 for (const char* p = comment; *p != '\0'; p++) {
965 if (*p == '"') { 980 if (*p == '"') {
966 msg.Append('\\'); 981 msg.Append('\\');
967 } 982 }
968 msg.Append(*p); 983 msg.Append(*p);
969 } 984 }
970 msg.Append('"'); 985 msg.Append('"');
971 msg.Append('\n'); 986 msg.Append('\n');
(...skipping 16 matching lines...) Expand all
988 } 1003 }
989 if (!log_->IsEnabled()) return; 1004 if (!log_->IsEnabled()) return;
990 if (FLAG_ll_prof) { 1005 if (FLAG_ll_prof) {
991 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size()); 1006 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size());
992 } 1007 }
993 if (Serializer::enabled()) { 1008 if (Serializer::enabled()) {
994 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size()); 1009 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size());
995 } 1010 }
996 if (!FLAG_log_code) return; 1011 if (!FLAG_log_code) return;
997 LogMessageBuilder msg(this); 1012 LogMessageBuilder msg(this);
998 msg.Append("%s,%s,", 1013 msg.Append("%s,%s,%d,",
999 kLogEventsNames[CODE_CREATION_EVENT], 1014 kLogEventsNames[CODE_CREATION_EVENT],
1000 kLogEventsNames[tag]); 1015 kLogEventsNames[tag],
1016 code->kind());
1001 msg.AppendAddress(code->address()); 1017 msg.AppendAddress(code->address());
1002 msg.Append(",%d,\"", code->ExecutableSize()); 1018 msg.Append(",%d,\"", code->ExecutableSize());
1003 msg.AppendDetailed(name, false); 1019 msg.AppendDetailed(name, false);
1004 msg.Append('"'); 1020 msg.Append('"');
1005 msg.Append('\n'); 1021 msg.Append('\n');
1006 msg.WriteToLogFile(); 1022 msg.WriteToLogFile();
1007 } 1023 }
1008 1024
1009 1025
1010 // ComputeMarker must only be used when SharedFunctionInfo is known. 1026 // ComputeMarker must only be used when SharedFunctionInfo is known.
(...skipping 29 matching lines...) Expand all
1040 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size()); 1056 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size());
1041 } 1057 }
1042 if (!FLAG_log_code) return; 1058 if (!FLAG_log_code) return;
1043 if (code == Isolate::Current()->builtins()->builtin( 1059 if (code == Isolate::Current()->builtins()->builtin(
1044 Builtins::kLazyCompile)) 1060 Builtins::kLazyCompile))
1045 return; 1061 return;
1046 1062
1047 LogMessageBuilder msg(this); 1063 LogMessageBuilder msg(this);
1048 SmartArrayPointer<char> str = 1064 SmartArrayPointer<char> str =
1049 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); 1065 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
1050 msg.Append("%s,%s,", 1066 msg.Append("%s,%s,%d,",
1051 kLogEventsNames[CODE_CREATION_EVENT], 1067 kLogEventsNames[CODE_CREATION_EVENT],
1052 kLogEventsNames[tag]); 1068 kLogEventsNames[tag],
1069 code->kind());
1053 msg.AppendAddress(code->address()); 1070 msg.AppendAddress(code->address());
1054 msg.Append(",%d,\"%s\",", code->ExecutableSize(), *str); 1071 msg.Append(",%d,\"%s\",", code->ExecutableSize(), *str);
1055 msg.AppendAddress(shared->address()); 1072 msg.AppendAddress(shared->address());
1056 msg.Append(",%s", ComputeMarker(code)); 1073 msg.Append(",%s", ComputeMarker(code));
1057 msg.Append('\n'); 1074 msg.Append('\n');
1058 msg.WriteToLogFile(); 1075 msg.WriteToLogFile();
1059 } 1076 }
1060 1077
1061 1078
1062 // Although, it is possible to extract source and line from 1079 // Although, it is possible to extract source and line from
(...skipping 24 matching lines...) Expand all
1087 } 1104 }
1088 if (Serializer::enabled()) { 1105 if (Serializer::enabled()) {
1089 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size()); 1106 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size());
1090 } 1107 }
1091 if (!FLAG_log_code) return; 1108 if (!FLAG_log_code) return;
1092 LogMessageBuilder msg(this); 1109 LogMessageBuilder msg(this);
1093 SmartArrayPointer<char> name = 1110 SmartArrayPointer<char> name =
1094 shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); 1111 shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
1095 SmartArrayPointer<char> sourcestr = 1112 SmartArrayPointer<char> sourcestr =
1096 source->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL); 1113 source->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
1097 msg.Append("%s,%s,", 1114 msg.Append("%s,%s,%d,",
1098 kLogEventsNames[CODE_CREATION_EVENT], 1115 kLogEventsNames[CODE_CREATION_EVENT],
1099 kLogEventsNames[tag]); 1116 kLogEventsNames[tag],
1117 code->kind());
1100 msg.AppendAddress(code->address()); 1118 msg.AppendAddress(code->address());
1101 msg.Append(",%d,\"%s %s:%d\",", 1119 msg.Append(",%d,\"%s %s:%d\",",
1102 code->ExecutableSize(), 1120 code->ExecutableSize(),
1103 *name, 1121 *name,
1104 *sourcestr, 1122 *sourcestr,
1105 line); 1123 line);
1106 msg.AppendAddress(shared->address()); 1124 msg.AppendAddress(shared->address());
1107 msg.Append(",%s", ComputeMarker(code)); 1125 msg.Append(",%s", ComputeMarker(code));
1108 msg.Append('\n'); 1126 msg.Append('\n');
1109 msg.WriteToLogFile(); 1127 msg.WriteToLogFile();
(...skipping 13 matching lines...) Expand all
1123 } 1141 }
1124 if (!log_->IsEnabled()) return; 1142 if (!log_->IsEnabled()) return;
1125 if (FLAG_ll_prof) { 1143 if (FLAG_ll_prof) {
1126 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size()); 1144 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size());
1127 } 1145 }
1128 if (Serializer::enabled()) { 1146 if (Serializer::enabled()) {
1129 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size()); 1147 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size());
1130 } 1148 }
1131 if (!FLAG_log_code) return; 1149 if (!FLAG_log_code) return;
1132 LogMessageBuilder msg(this); 1150 LogMessageBuilder msg(this);
1133 msg.Append("%s,%s,", 1151 msg.Append("%s,%s,%d,",
1134 kLogEventsNames[CODE_CREATION_EVENT], 1152 kLogEventsNames[CODE_CREATION_EVENT],
1135 kLogEventsNames[tag]); 1153 kLogEventsNames[tag],
1154 code->kind());
1136 msg.AppendAddress(code->address()); 1155 msg.AppendAddress(code->address());
1137 msg.Append(",%d,\"args_count: %d\"", code->ExecutableSize(), args_count); 1156 msg.Append(",%d,\"args_count: %d\"", code->ExecutableSize(), args_count);
1138 msg.Append('\n'); 1157 msg.Append('\n');
1139 msg.WriteToLogFile(); 1158 msg.WriteToLogFile();
1140 } 1159 }
1141 1160
1142 1161
1143 void Logger::CodeMovingGCEvent() { 1162 void Logger::CodeMovingGCEvent() {
1144 if (!log_->IsEnabled() || !FLAG_ll_prof) return; 1163 if (!log_->IsEnabled() || !FLAG_ll_prof) return;
1145 LowLevelLogWriteBytes(&kCodeMovingGCTag, sizeof(kCodeMovingGCTag)); 1164 LowLevelLogWriteBytes(&kCodeMovingGCTag, sizeof(kCodeMovingGCTag));
(...skipping 14 matching lines...) Expand all
1160 } 1179 }
1161 if (!log_->IsEnabled()) return; 1180 if (!log_->IsEnabled()) return;
1162 if (FLAG_ll_prof) { 1181 if (FLAG_ll_prof) {
1163 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size()); 1182 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size());
1164 } 1183 }
1165 if (Serializer::enabled()) { 1184 if (Serializer::enabled()) {
1166 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size()); 1185 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size());
1167 } 1186 }
1168 if (!FLAG_log_code) return; 1187 if (!FLAG_log_code) return;
1169 LogMessageBuilder msg(this); 1188 LogMessageBuilder msg(this);
1170 msg.Append("%s,%s,", 1189 msg.Append("%s,%s,-2,",
1171 kLogEventsNames[CODE_CREATION_EVENT], 1190 kLogEventsNames[CODE_CREATION_EVENT],
1172 kLogEventsNames[REG_EXP_TAG]); 1191 kLogEventsNames[REG_EXP_TAG]);
1173 msg.AppendAddress(code->address()); 1192 msg.AppendAddress(code->address());
1174 msg.Append(",%d,\"", code->ExecutableSize()); 1193 msg.Append(",%d,\"", code->ExecutableSize());
1175 msg.AppendDetailed(source, false); 1194 msg.AppendDetailed(source, false);
1176 msg.Append('\"'); 1195 msg.Append('\"');
1177 msg.Append('\n'); 1196 msg.Append('\n');
1178 msg.WriteToLogFile(); 1197 msg.WriteToLogFile();
1179 } 1198 }
1180 1199
(...skipping 159 matching lines...) Expand 10 before | Expand all | Expand 10 after
1340 } 1359 }
1341 1360
1342 1361
1343 void Logger::TickEvent(TickSample* sample, bool overflow) { 1362 void Logger::TickEvent(TickSample* sample, bool overflow) {
1344 if (!log_->IsEnabled() || !FLAG_prof) return; 1363 if (!log_->IsEnabled() || !FLAG_prof) return;
1345 LogMessageBuilder msg(this); 1364 LogMessageBuilder msg(this);
1346 msg.Append("%s,", kLogEventsNames[TICK_EVENT]); 1365 msg.Append("%s,", kLogEventsNames[TICK_EVENT]);
1347 msg.AppendAddress(sample->pc); 1366 msg.AppendAddress(sample->pc);
1348 msg.Append(','); 1367 msg.Append(',');
1349 msg.AppendAddress(sample->sp); 1368 msg.AppendAddress(sample->sp);
1369 msg.Append(",%ld",
1370 FLAG_log_timer_events ? static_cast<int>(OS::Ticks() - epoch_) : 0);
1350 if (sample->has_external_callback) { 1371 if (sample->has_external_callback) {
1351 msg.Append(",1,"); 1372 msg.Append(",1,");
1352 msg.AppendAddress(sample->external_callback); 1373 msg.AppendAddress(sample->external_callback);
1353 } else { 1374 } else {
1354 msg.Append(",0,"); 1375 msg.Append(",0,");
1355 msg.AppendAddress(sample->tos); 1376 msg.AppendAddress(sample->tos);
1356 } 1377 }
1357 msg.Append(",%d", static_cast<int>(sample->state)); 1378 msg.Append(",%d", static_cast<int>(sample->state));
1358 if (overflow) { 1379 if (overflow) {
1359 msg.Append(",overflow"); 1380 msg.Append(",overflow");
(...skipping 537 matching lines...) Expand 10 before | Expand all | Expand 10 after
1897 void SamplerRegistry::RemoveActiveSampler(Sampler* sampler) { 1918 void SamplerRegistry::RemoveActiveSampler(Sampler* sampler) {
1898 ASSERT(sampler->IsActive()); 1919 ASSERT(sampler->IsActive());
1899 ScopedLock lock(active_samplers_mutex); 1920 ScopedLock lock(active_samplers_mutex);
1900 ASSERT(active_samplers_ != NULL); 1921 ASSERT(active_samplers_ != NULL);
1901 bool removed = active_samplers_->RemoveElement(sampler); 1922 bool removed = active_samplers_->RemoveElement(sampler);
1902 ASSERT(removed); 1923 ASSERT(removed);
1903 USE(removed); 1924 USE(removed);
1904 } 1925 }
1905 1926
1906 } } // namespace v8::internal 1927 } } // namespace v8::internal
OLDNEW
« no previous file with comments | « src/log.h ('k') | src/vm-state-inl.h » ('j') | tools/plot-timer-events.js » ('J')

Powered by Google App Engine
This is Rietveld 408576698