[logging] correctly log code events from deserialization.

R=jarin@chromium.org

Bug: v8:8671, v8:8674
Change-Id: I5cdcd49d05f08206aa32426f2fe0560568291f2e
Reviewed-on: https://chromium-review.googlesource.com/c/1405852
Commit-Queue: Yang Guo <yangguo@chromium.org>
Reviewed-by: Jaroslav Sevcik <jarin@chromium.org>
Cr-Commit-Position: refs/heads/master@{#58739}

src/log.cc

@@ -203,6 +203,7 @@ void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
                                       SharedFunctionInfo shared, Name name) {
   name_buffer_->Init(tag);
   name_buffer_->AppendBytes(ComputeMarker(shared, code));
+  name_buffer_->AppendByte(' ');
   name_buffer_->AppendName(name);
   LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());
 }

src/snapshot/code-serializer.cc

@@ -276,23 +276,35 @@ MaybeHandle<SharedFunctionInfo> CodeSerializer::Deserialize(
     PrintF("[Deserializing from %d bytes took %0.3f ms]\n", length, ms);
   }
 
-  bool log_code_creation = isolate->logger()->is_listening_to_code_events() ||
-                           isolate->is_profiling();
+  bool log_code_creation =
+      isolate->logger()->is_listening_to_code_events() ||
+      isolate->is_profiling() ||
+      isolate->code_event_dispatcher()->IsListeningToCodeEvents();
   if (log_code_creation || FLAG_log_function_events) {
     String name = ReadOnlyRoots(isolate).empty_string();
-    if (result->script()->IsScript()) {
-      Script script = Script::cast(result->script());
-      if (script->name()->IsString()) name = String::cast(script->name());
-      if (FLAG_log_function_events) {
-        LOG(isolate, FunctionEvent("deserialize", script->id(),
-                                   timer.Elapsed().InMillisecondsF(),
-                                   result->StartPosition(),
-                                   result->EndPosition(), name));
-      }
+    Script script = Script::cast(result->script());
+    Handle<Script> script_handle(script, isolate);
+    if (script->name()->IsString()) name = String::cast(script->name());
+    if (FLAG_log_function_events) {
+      LOG(isolate,
+          FunctionEvent("deserialize", script->id(),
+                        timer.Elapsed().InMillisecondsF(),
+                        result->StartPosition(), result->EndPosition(), name));
     }
     if (log_code_creation) {
-      PROFILE(isolate, CodeCreateEvent(CodeEventListener::SCRIPT_TAG,
-                                       result->abstract_code(), *result, name));
+      Script::InitLineEnds(Handle<Script>(script, isolate));
+      DisallowHeapAllocation no_gc;
+      SharedFunctionInfo::ScriptIterator iter(isolate, script);
+      for (i::SharedFunctionInfo info = iter.Next(); !info.is_null();
+           info = iter.Next()) {
+        if (info->is_compiled()) {
+          int line_num = script->GetLineNumber(info->StartPosition()) + 1;
+          int column_num = script->GetColumnNumber(info->StartPosition()) + 1;
+          PROFILE(isolate, CodeCreateEvent(CodeEventListener::SCRIPT_TAG,
+                                           info->abstract_code(), info, name,
+                                           line_num, column_num));
+        }
+      }
     }
   }
 

test/cctest/test-log.cc

@@ -671,7 +671,7 @@ TEST(ExternalCodeEventListener) {
     v8::HandleScope scope(isolate);
     v8::Isolate::Scope isolate_scope(isolate);
     v8::Local<v8::Context> context = v8::Context::New(isolate);
-    context->Enter();
+    v8::Context::Scope context_scope(context);
 
     TestCodeEventHandler code_event_handler(isolate);
 
@@ -698,12 +698,68 @@ TEST(ExternalCodeEventListener) {
     CHECK_GE(code_event_handler.CountLines("LazyCompile",
                                            "testCodeEventListenerAfterStart"),
              1);
-
-    context->Exit();
   }
   isolate->Dispose();
 }
 
+TEST(ExternalCodeEventListenerInnerFunctions) {
+  i::FLAG_log = false;
+  i::FLAG_prof = false;
+
+  v8::ScriptCompiler::CachedData* cache;
+  static const char* source_cstring =
+      "(function f1() { return (function f2() {}); })()";
+
+  v8::Isolate::CreateParams create_params;
+  create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
+  v8::Isolate* isolate1 = v8::Isolate::New(create_params);
+  {  // Test that we emit the correct code events from eagerly compiling.
+    v8::HandleScope scope(isolate1);
+    v8::Isolate::Scope isolate_scope(isolate1);
+    v8::Local<v8::Context> context = v8::Context::New(isolate1);
+    v8::Context::Scope context_scope(context);
+
+    TestCodeEventHandler code_event_handler(isolate1);
+    code_event_handler.Enable();
+
+    v8::Local<v8::String> source_string = v8_str(source_cstring);
+    v8::ScriptOrigin origin(v8_str("test"));
+    v8::ScriptCompiler::Source source(source_string, origin);
+    v8::Local<v8::UnboundScript> script =
+        v8::ScriptCompiler::CompileUnboundScript(isolate1, &source)
+            .ToLocalChecked();
+    CHECK_EQ(code_event_handler.CountLines("Script", "f1"), 1);
+    CHECK_EQ(code_event_handler.CountLines("Script", "f2"), 1);
+    cache = v8::ScriptCompiler::CreateCodeCache(script);
+  }
+  isolate1->Dispose();
+
+  v8::Isolate* isolate2 = v8::Isolate::New(create_params);
+  {  // Test that we emit the correct code events from deserialization.
+    v8::HandleScope scope(isolate2);
+    v8::Isolate::Scope isolate_scope(isolate2);
+    v8::Local<v8::Context> context = v8::Context::New(isolate2);
+    v8::Context::Scope context_scope(context);
+
+    TestCodeEventHandler code_event_handler(isolate2);
+    code_event_handler.Enable();
+
+    v8::Local<v8::String> source_string = v8_str(source_cstring);
+    v8::ScriptOrigin origin(v8_str("test"));
+    v8::ScriptCompiler::Source source(source_string, origin, cache);
+    {
+      i::DisallowCompilation no_compile_expected(
+          reinterpret_cast<i::Isolate*>(isolate2));
+      v8::ScriptCompiler::CompileUnboundScript(
+          isolate2, &source, v8::ScriptCompiler::kConsumeCodeCache)
+          .ToLocalChecked();
+    }
+    CHECK_EQ(code_event_handler.CountLines("Script", "f1"), 1);
+    CHECK_EQ(code_event_handler.CountLines("Script", "f2"), 1);
+  }
+  isolate2->Dispose();
+}
+
 TEST(ExternalCodeEventListenerWithInterpretedFramesNativeStack) {
   i::FLAG_log = false;
   i::FLAG_prof = false;

test/cctest/test-serialize.cc

@@ -2184,8 +2184,8 @@ static bool toplevel_test_code_event_found = false;
 
 static void SerializerCodeEventListener(const v8::JitCodeEvent* event) {
   if (event->type == v8::JitCodeEvent::CODE_ADDED &&
-      (memcmp(event->name.str, "Script:~test", 12) == 0 ||
-       memcmp(event->name.str, "Script:test", 11) == 0)) {
+      (memcmp(event->name.str, "Script:~ test", 13) == 0 ||
+       memcmp(event->name.str, "Script: test", 12) == 0)) {
     toplevel_test_code_event_found = true;
   }
 }