[profiler] Web UI: add summary of opts/deopts.

src/log.cc

Index: src/log.cc
diff --git a/src/log.cc b/src/log.cc
index 46872a150c48259ca932d7c6e06f1e70a89cc483..aa01a2f0ac02c27fb4c70c0e389c3f5409e47586 100644
--- a/src/log.cc
+++ b/src/log.cc
@@ -843,12 +843,41 @@ void Logger::SharedLibraryEvent(const std::string& library_path,
   msg.WriteToLogFile();
 }
 
-
-void Logger::CodeDeoptEvent(Code* code, Address pc, int fp_to_sp_delta) {
-  if (!log_->IsEnabled() || !FLAG_log_internal_timer_events) return;
+void Logger::CodeDeoptEvent(DeoptKind kind, Code* code, Address pc,
+                            int fp_to_sp_delta) {
+  if (!log_->IsEnabled()) return;
+  Deoptimizer::DeoptInfo info = Deoptimizer::GetDeoptInfo(code, pc);
   Log::MessageBuilder msg(log_);
   int since_epoch = static_cast<int>(timer_.Elapsed().InMicroseconds());
-  msg.Append("code-deopt,%d,%d", since_epoch, code->CodeSize());
+  msg.Append("code-deopt,%d,%d,", since_epoch, code->CodeSize());
+  msg.AppendAddress(code->address());
+
+  // Deoptimization position.
+  std::ostringstream deopt_location;
+  int inlining_id = -1;
+  int script_offset = -1;
+  if (info.position.IsKnown()) {
+    info.position.Print(deopt_location, code);
+    inlining_id = info.position.InliningId();
+    script_offset = info.position.ScriptOffset();
+  } else {
+    deopt_location << "<unknown>";
+  }
+  msg.Append(",%d,%d,", inlining_id, script_offset);
+  switch (kind) {
+    case kLazy:
+      msg.Append("\"lazy\",");
+      break;
+    case kSoft:
+      msg.Append("\"soft\",");
+      break;
+    case kEager:
+      msg.Append("\"eager\",");
+      break;
+  }
+  msg.AppendDoubleQuotedString(deopt_location.str().c_str());
+  msg.Append(",");
+  msg.AppendDoubleQuotedString(DeoptimizeReasonToString(info.deopt_reason));
   msg.WriteToLogFile();
 }
 
@@ -972,6 +1001,11 @@ void Logger::CallbackEventInternal(const char* prefix, Name* name,
   msg.Append("%s,%s,-2,",
              kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT],
              kLogEventsNames[CodeEventListener::CALLBACK_TAG]);
+  if (timer_.IsStarted()) {
+    msg.Append("%d,", static_cast<int>(timer_.Elapsed().InMicroseconds()));
+  } else {
+    msg.Append("-1,");
+  }
   msg.AppendAddress(entry_point);
   if (name->IsString()) {
     std::unique_ptr<char[]> str =
@@ -1007,23 +1041,31 @@ void Logger::SetterCallbackEvent(Name* name, Address entry_point) {
   CallbackEventInternal("set ", name, entry_point);
 }
 
-static void AppendCodeCreateHeader(Log::MessageBuilder* msg,
-                                   CodeEventListener::LogEventsAndTags tag,
-                                   AbstractCode* code) {
+namespace {
+
+void AppendCodeCreateHeader(Log::MessageBuilder* msg,
+                            CodeEventListener::LogEventsAndTags tag,
+                            AbstractCode* code, base::ElapsedTimer* timer) {
   DCHECK(msg);
   msg->Append("%s,%s,%d,",
               kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT],
               kLogEventsNames[tag], code->kind());
+  int timestamp = timer->IsStarted()

[Leszek Swirski, 2017/03/21 14:28:39]

nit: inconsistent use of if blocks vs. ternary operator -- either is fine with
me

+                      ? static_cast<int>(timer->Elapsed().InMicroseconds())
+                      : -1;
+  msg->Append("%d,", timestamp);
   msg->AppendAddress(code->address());
   msg->Append(",%d,", code->ExecutableSize());
 }
 
+}  // namespace
+
 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
                              AbstractCode* code, const char* comment) {
   if (!is_logging_code_events()) return;
   if (!FLAG_log_code || !log_->IsEnabled()) return;
   Log::MessageBuilder msg(log_);
-  AppendCodeCreateHeader(&msg, tag, code);
+  AppendCodeCreateHeader(&msg, tag, code, &timer_);
   msg.AppendDoubleQuotedString(comment);
   msg.WriteToLogFile();
 }
@@ -1033,7 +1075,7 @@ void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
   if (!is_logging_code_events()) return;
   if (!FLAG_log_code || !log_->IsEnabled()) return;
   Log::MessageBuilder msg(log_);
-  AppendCodeCreateHeader(&msg, tag, code);
+  AppendCodeCreateHeader(&msg, tag, code, &timer_);
   if (name->IsString()) {
     msg.Append('"');
     msg.AppendDetailed(String::cast(name), false);
@@ -1055,7 +1097,7 @@ void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
   }
 
   Log::MessageBuilder msg(log_);
-  AppendCodeCreateHeader(&msg, tag, code);
+  AppendCodeCreateHeader(&msg, tag, code, &timer_);
   if (name->IsString()) {
     std::unique_ptr<char[]> str =
         String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
@@ -1079,7 +1121,7 @@ void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
   if (!is_logging_code_events()) return;
   if (!FLAG_log_code || !log_->IsEnabled()) return;
   Log::MessageBuilder msg(log_);
-  AppendCodeCreateHeader(&msg, tag, code);
+  AppendCodeCreateHeader(&msg, tag, code, &timer_);
   std::unique_ptr<char[]> name =
       shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   msg.Append("\"%s ", name.get());
@@ -1101,7 +1143,7 @@ void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
   if (!is_logging_code_events()) return;
   if (!FLAG_log_code || !log_->IsEnabled()) return;
   Log::MessageBuilder msg(log_);
-  AppendCodeCreateHeader(&msg, tag, code);
+  AppendCodeCreateHeader(&msg, tag, code, &timer_);
   msg.Append("\"args_count: %d\"", args_count);
   msg.WriteToLogFile();
 }
@@ -1130,7 +1172,7 @@ void Logger::RegExpCodeCreateEvent(AbstractCode* code, String* source) {
   if (!is_logging_code_events()) return;
   if (!FLAG_log_code || !log_->IsEnabled()) return;
   Log::MessageBuilder msg(log_);
-  AppendCodeCreateHeader(&msg, CodeEventListener::REG_EXP_TAG, code);
+  AppendCodeCreateHeader(&msg, CodeEventListener::REG_EXP_TAG, code, &timer_);
   msg.Append('"');
   msg.AppendDetailed(source, false);
   msg.Append('"');