Fall back to inlining intervals to generate stack traces in --noopt. Inlined frames will lack line and column positions, but they will at least be expanded.

Fix stack traces when visible functions are inlined into an invisible function.

Fix off-by-one expanding inlined functions in the profiler.

BUG=http://dartbug.com/24783
[email protected]

Review URL: https://codereview.chromium.org/1582683003 .

Author: rmacnak-google

runtime/tests/vm/vm.status

@@ -86,8 +86,8 @@ dart/byte_array_test: Crash # Incompatible flag --disable_alloc_stubs_after_gc
 
 [ $noopt || $compiler == precompiler ]
 dart/redirection_type_shuffling_test: CompileTimeError # Imports dart:mirrors
-dart/inline_stack_frame_test: Fail  # Issue 24783 - inlined frames missing
+dart/optimized_stacktrace_test: RuntimeError # Expects line and column numbers
 
 [ $runtime == dart_precompiled ]
-dart/optimized_stacktrace_test: Fail
+dart/inline_stack_frame_test: Fail  # Issue 24783 - inlined frames missing
 dart/data_uri_spawn_test: RuntimeError # Isolate.spawnUri

runtime/vm/object.cc

@@ -21600,6 +21600,23 @@ static intptr_t PrintOneStacktrace(Zone* zone,
 }
 
 
+static intptr_t PrintOneStacktraceNoCode(Zone* zone,
+                                         GrowableArray<char*>* frame_strings,
+                                         const Function& function,
+                                         intptr_t frame_index) {
+  const Script& script = Script::Handle(zone, function.script());
+  const String& function_name =
+      String::Handle(zone, function.QualifiedUserVisibleName());
+  const String& url = String::Handle(zone, script.url());
+  char* chars = NULL;
+  chars = OS::SCreate(zone,
+      "#%-6" Pd " %s (%s)\n",
+      frame_index, function_name.ToCString(), url.ToCString());
+  frame_strings->Add(chars);
+  return strlen(chars);
+}
+
+
 const char* Stacktrace::ToCStringInternal(intptr_t* frame_index,
                                           intptr_t max_frames) const {
   Zone* zone = Thread::Current()->zone();
@@ -21612,7 +21629,8 @@ const char* Stacktrace::ToCStringInternal(intptr_t* frame_index,
   for (intptr_t i = 0; (i < Length()) && (*frame_index < max_frames); i++) {
     function = FunctionAtFrame(i);
     if (function.IsNull()) {
-      // Check if null function object indicates a stack trace overflow.
+      // Check if null function object indicates a gap in a StackOverflow or
+      // OutOfMemory trace.
       if ((i < (Length() - 1)) &&
           (FunctionAtFrame(i + 1) != Function::null())) {
         const char* kTruncated = "...\n...\n";
@@ -21622,31 +21640,55 @@ const char* Stacktrace::ToCStringInternal(intptr_t* frame_index,
         frame_strings.Add(chars);
         total_len += truncated_len;
       }
-    } else if (function.is_visible() || FLAG_show_invisible_frames) {
+    } else {
       code = CodeAtFrame(i);
       ASSERT(function.raw() == code.function());
       uword pc = code.EntryPoint() + Smi::Value(PcOffsetAtFrame(i));
       if (code.is_optimized() && expand_inlined()) {
         // Traverse inlined frames.
-        for (InlinedFunctionsIterator it(code, pc);
-             !it.Done() && (*frame_index < max_frames); it.Advance()) {
-          function = it.function();
-          if (function.is_visible() || FLAG_show_invisible_frames) {
-            code = it.code();
-            ASSERT(function.raw() == code.function());
-            uword pc = it.pc();
-            ASSERT(pc != 0);
-            ASSERT(code.EntryPoint() <= pc);
-            ASSERT(pc < (code.EntryPoint() + code.Size()));
-            total_len += PrintOneStacktrace(
-                zone, &frame_strings, pc, function, code, *frame_index);
-            (*frame_index)++;  // To account for inlined frames.
+        if (Compiler::allow_recompilation()) {
+          for (InlinedFunctionsIterator it(code, pc);
+               !it.Done() && (*frame_index < max_frames); it.Advance()) {
+            function = it.function();
+            if (function.is_visible() || FLAG_show_invisible_frames) {
+              code = it.code();
+              ASSERT(function.raw() == code.function());
+              uword pc = it.pc();
+              ASSERT(pc != 0);
+              ASSERT(code.EntryPoint() <= pc);
+              ASSERT(pc < (code.EntryPoint() + code.Size()));
+              total_len += PrintOneStacktrace(
+                  zone, &frame_strings, pc, function, code, *frame_index);
+              (*frame_index)++;  // To account for inlined frames.
+            }
+          }
+        } else {
+          // Precompilation: we don't have deopt info, so we don't know the
+          // source position of inlined functions, but we can still name them.
+          intptr_t offset = Smi::Value(PcOffsetAtFrame(i));
+          // The PC of frames below the top frame is a call's return address,
+          // which can belong to a different inlining interval than the call.
+          intptr_t effective_offset = offset - 1;
+          GrowableArray<Function*> inlined_functions;
+          code.GetInlinedFunctionsAt(effective_offset, &inlined_functions);
+          ASSERT(inlined_functions.length() >= 1);  // At least the inliner.
+          for (intptr_t j = 0; j < inlined_functions.length(); j++) {
+            Function* inlined_function = inlined_functions[j];
+            ASSERT(inlined_function != NULL);
+            ASSERT(!inlined_function->IsNull());
+            if (inlined_function->is_visible() || FLAG_show_invisible_frames) {
+              total_len += PrintOneStacktraceNoCode(
+                  zone, &frame_strings, *inlined_function, *frame_index);
+              (*frame_index)++;
+            }
           }
         }
       } else {
-        total_len += PrintOneStacktrace(
-            zone, &frame_strings, pc, function, code, *frame_index);
-        (*frame_index)++;
+        if (function.is_visible() || FLAG_show_invisible_frames) {
+          total_len += PrintOneStacktrace(
+              zone, &frame_strings, pc, function, code, *frame_index);
+          (*frame_index)++;
+        }
       }
     }
   }

runtime/vm/profiler_service.cc

@@ -1390,6 +1390,11 @@ class ProfileBuilder : public ValueObject {
     GrowableArray<Function*> inlined_functions;
     if (!code.IsNull()) {
       intptr_t offset = pc - code.EntryPoint();
+      if (frame_index != 0) {
+        // The PC of frames below the top frame is a call's return address,
+        // which can belong to a different inlining interval than the call.
+        offset--;
+      }
       code.GetInlinedFunctionsAt(offset, &inlined_functions);
     }
     if (code.IsNull() || (inlined_functions.length() == 0)) {

runtime/vm/profiler_test.cc

@@ -34,6 +34,22 @@ class DisableNativeProfileScope : public ValueObject {
 };
 
 
+class DisableBackgroundCompilationScope : public ValueObject {
+ public:
+  DisableBackgroundCompilationScope()
+      : FLAG_background_compilation_(FLAG_background_compilation) {
+    FLAG_background_compilation = false;
+  }
+
+  ~DisableBackgroundCompilationScope() {
+    FLAG_background_compilation = FLAG_background_compilation_;
+  }
+
+ private:
+  const bool FLAG_background_compilation_;
+};
+
+
 // Temporarily adjust the maximum profile depth.
 class MaxProfileDepthScope : public ValueObject {
  public:
@@ -139,6 +155,7 @@ TEST_CASE(Profiler_AllocationSampleTest) {
   delete sample_buffer;
 }
 
+
 static RawClass* GetClass(const Library& lib, const char* name) {
   const Class& cls = Class::Handle(
       lib.LookupClassAllowPrivate(String::Handle(Symbols::New(name))));
@@ -147,6 +164,14 @@ static RawClass* GetClass(const Library& lib, const char* name) {
 }
 
 
+static RawFunction* GetFunction(const Library& lib, const char* name) {
+  const Function& func = Function::Handle(
+      lib.LookupFunctionAllowPrivate(String::Handle(Symbols::New(name))));
+  EXPECT(!func.IsNull());  // No ambiguity error expected.
+  return func.raw();
+}
+
+
 class AllocationFilter : public SampleFilter {
  public:
   AllocationFilter(Isolate* isolate,
@@ -1154,6 +1179,8 @@ TEST_CASE(Profiler_StringInterpolation) {
 
 TEST_CASE(Profiler_FunctionInline) {
   DisableNativeProfileScope dnps;
+  DisableBackgroundCompilationScope dbcs;
+
   const char* kScript =
       "class A {\n"
       "  var a;\n"
@@ -1180,8 +1207,6 @@ TEST_CASE(Profiler_FunctionInline) {
       "  B.boo(true);\n"
       "}\n";
 
-  const bool old_flag = FLAG_background_compilation;
-  FLAG_background_compilation = false;
   Dart_Handle lib = TestCase::LoadTestScript(kScript, NULL);
   EXPECT_VALID(lib);
   Library& root_library = Library::Handle();
@@ -1398,7 +1423,133 @@ TEST_CASE(Profiler_FunctionInline) {
     EXPECT_STREQ("[Inline End]", walker.CurrentName());
     EXPECT(!walker.Down());
   }
-  FLAG_background_compilation = old_flag;
+}
+
+
+TEST_CASE(Profiler_InliningIntervalBoundry) {
+  // The PC of frames below the top frame is a call's return address,
+  // which can belong to a different inlining interval than the call.
+  // This test checks the profiler service takes this into account; see
+  // ProfileBuilder::ProcessFrame.
+
+  DisableNativeProfileScope dnps;
+  DisableBackgroundCompilationScope dbcs;
+  const char* kScript =
+      "class A {\n"
+      "}\n"
+      "bool alloc = false;"
+      "maybeAlloc() {\n"
+      "  try {\n"
+      "    if (alloc) new A();\n"
+      "  } catch (e) {\n"
+      "  }\n"
+      "}\n"
+      "right() => maybeAlloc();\n"
+      "doNothing() {\n"
+      "  try {\n"
+      "  } catch (e) {\n"
+      "  }\n"
+      "}\n"
+      "wrong() => doNothing();\n"
+      "a() {\n"
+      "  try {\n"
+      "    right();\n"
+      "    wrong();\n"
+      "  } catch (e) {\n"
+      "  }\n"
+      "}\n"
+      "mainNoAlloc() {\n"
+      "  for (var i = 0; i < 20000; i++) {\n"
+      "    a();\n"
+      "  }\n"
+      "}\n"
+      "mainAlloc() {\n"
+      "  alloc = true;\n"
+      "  a();\n"
+      "}\n";
+
+  Dart_Handle lib = TestCase::LoadTestScript(kScript, NULL);
+  EXPECT_VALID(lib);
+  Library& root_library = Library::Handle();
+  root_library ^= Api::UnwrapHandle(lib);
+
+  const Class& class_a = Class::Handle(GetClass(root_library, "A"));
+  EXPECT(!class_a.IsNull());
+
+  // Compile and optimize.
+  Dart_Handle result = Dart_Invoke(lib, NewString("mainNoAlloc"), 0, NULL);
+  EXPECT_VALID(result);
+  result = Dart_Invoke(lib, NewString("mainAlloc"), 0, NULL);
+  EXPECT_VALID(result);
+
+  // At this point a should be optimized and have inlined both right and wrong,
+  // but not maybeAllocate or doNothing.
+  Function& func = Function::Handle();
+  func = GetFunction(root_library, "a");
+  EXPECT(!func.is_inlinable());
+  EXPECT(func.HasOptimizedCode());
+  func = GetFunction(root_library, "right");
+  EXPECT(func.is_inlinable());
+  func = GetFunction(root_library, "wrong");
+  EXPECT(func.is_inlinable());
+  func = GetFunction(root_library, "doNothing");
+  EXPECT(!func.is_inlinable());
+  func = GetFunction(root_library, "maybeAlloc");
+  EXPECT(!func.is_inlinable());
+
+  {
+    Thread* thread = Thread::Current();
+    Isolate* isolate = thread->isolate();
+    StackZone zone(thread);
+    HANDLESCOPE(thread);
+    Profile profile(isolate);
+    AllocationFilter filter(isolate, class_a.id());
+    profile.Build(thread, &filter, Profile::kNoTags);
+    // We should have no allocation samples.
+    EXPECT_EQ(0, profile.sample_count());
+  }
+
+  // Turn on allocation tracing for A.
+  class_a.SetTraceAllocation(true);
+
+  result = Dart_Invoke(lib, NewString("mainAlloc"), 0, NULL);
+  EXPECT_VALID(result);
+
+  {
+    Thread* thread = Thread::Current();
+    Isolate* isolate = thread->isolate();
+    StackZone zone(thread);
+    HANDLESCOPE(thread);
+    Profile profile(isolate);
+    AllocationFilter filter(isolate, class_a.id());
+    profile.Build(thread, &filter, Profile::kNoTags);
+    EXPECT_EQ(1, profile.sample_count());
+    ProfileTrieWalker walker(&profile);
+
+    // Inline expansion should show us the complete call chain:
+    walker.Reset(Profile::kExclusiveFunction);
+    EXPECT(walker.Down());
+    EXPECT_STREQ("maybeAlloc", walker.CurrentName());
+    EXPECT(walker.Down());
+    EXPECT_STREQ("right", walker.CurrentName());
+    EXPECT(walker.Down());
+    EXPECT_STREQ("a", walker.CurrentName());
+    EXPECT(walker.Down());
+    EXPECT_STREQ("mainAlloc", walker.CurrentName());
+    EXPECT(!walker.Down());
+
+    // Inline expansion should show us the complete call chain:
+    walker.Reset(Profile::kInclusiveFunction);
+    EXPECT(walker.Down());
+    EXPECT_STREQ("mainAlloc", walker.CurrentName());
+    EXPECT(walker.Down());
+    EXPECT_STREQ("a", walker.CurrentName());
+    EXPECT(walker.Down());
+    EXPECT_STREQ("right", walker.CurrentName());
+    EXPECT(walker.Down());
+    EXPECT_STREQ("maybeAlloc", walker.CurrentName());
+    EXPECT(!walker.Down());
+  }
 }
 
 

tests/language/language.status

@@ -133,6 +133,7 @@ super_getter_setter_test: CompileTimeError
 vm/reflect_core_vm_test: CompileTimeError
 redirecting_factory_reflection_test: CompileTimeError
 deferred_constraints_constants_test: Skip # multitest gets confused
+vm/type_vm_test: RuntimeError # Expects line and column numbers
 
 # Deferred loading happens eagerly
 regress_23408_test: RuntimeError
@@ -143,7 +144,6 @@ deferred_load_constants_test: Skip # multitest gets confused
 deopt_inlined_function_lazy_test: Pass, Crash # Incompatible flag: --deoptimize-alot
 tearoff_basic_test: RuntimeError, Crash # Conflicting flag.
 vm/type_cast_vm_test: RuntimeError # Line number mismatch.
-stack_trace_test: Fail  # Issue 24783 - inlined frames missing
 
 [ $runtime == dart_precompiled ]
 ct_const2_test: Pass, Crash # Incompatible flag --compile_all

tests/standalone/standalone.status

@@ -222,6 +222,7 @@ io/secure_socket_bad_data_test: RuntimeError  # An error in a secure connection
 map_literal_oom_test: Pass, Crash # Issue 24678
 javascript*: SkipByDesign # JS overflow flag unsupported
 io/web_socket_test: Pass, RuntimeError # Issue 24674
+assert_test: RuntimeError # Expects line and column numbers
 
 [ $runtime == dart_precompiled ]
 debugger/*: Skip