dart-lang / sdk

The Dart SDK, including the VM, JS and Wasm compilers, analysis, core libraries, and more.
https://dart.dev
BSD 3-Clause "New" or "Revised" License
10.23k stars 1.57k forks source link

SlowTypeTest is slow in JIT (related to Records it seems) #54928

Open jensjoha opened 8 months ago

jensjoha commented 8 months ago

TL;DR: Replacing records with classes in a few maps reduces runtime with ~28% and makes SlowTypeTest go from taking ~22% of the time to basically taking nothing. This is only true for JIT, not with AOT.

Preface that isn't really that important I noticed that that for the try bots I was always waiting for two bots to finish, one of them being "pkg-linux-release-try" and that in particular the test "pkg/dartdev/test/commands/doc_test" took almost 10 minutes to run on the bot. Needing to clear my brain of what I was doing I thought I'd take a look. The test runs several iterations of "dart doc [...]" on some test code. To only look at one I applied this patch:

diff --git a/pkg/dartdev/test/commands/doc_test.dart b/pkg/dartdev/test/commands/doc_test.dart
index 52ab314a839..0b0336659e1 100644
--- a/pkg/dartdev/test/commands/doc_test.dart
+++ b/pkg/dartdev/test/commands/doc_test.dart
@@ -2,6 +2,8 @@
 // for details. All rights reserved. Use of this source code is governed by a
 // BSD-style license that can be found in the LICENSE file.

+import 'dart:io';
+
 import 'package:test/test.dart';

 import '../utils.dart';
@@ -62,7 +64,7 @@ class Bar {
     expect(result.exitCode, 0);
   });

-  test('Document a library', () async {
+  test('Document a library', solo: true, () async {
     final p = project(mainSrc: 'void main() { print("Hello, World"); }');
     p.file('lib/foo.dart', '''
 /// This is Foo. It uses [Bar].
@@ -76,6 +78,10 @@ class Bar {
 }
 ''');
     final result = await p.run(['doc', '--validate-links', p.dirPath]);
+    if (1+1==2) {
+      print("Will now exit, without cleaning up");
+      exit(1);
+    }
     expect(result.stdout, contains('Documenting dartdev_temp'));
     expect(result.exitCode, 0);
   });

and ran the test - I now had an input and I could run dartdev with this input "stand alone": for me time out/ReleaseX64/dart-sdk/bin/dart pkg/dartdev/bin/dartdev.dart doc /tmp/dartdevFAVRIP/myapp -v (though to be fair I also ran dart pub get in the temp dir to get rid of assert errors).

One thing led to another and I eventually tried replacing some records with classes for keys in maps: (in the dir third_party/pkg/dartdoc/, e.g. $ pushd third_party/pkg/dartdoc/):

diff --git a/lib/src/model/model_element.dart b/lib/src/model/model_element.dart
index 7b048864..b2b8e7c3 100644
--- a/lib/src/model/model_element.dart
+++ b/lib/src/model/model_element.dart
@@ -174,7 +174,7 @@ abstract class ModelElement extends Canonicalization

     // Return the cached ModelElement if it exists.
     var cachedModelElement = packageGraph
-        .allConstructedModelElements[(e, library, enclosingContainer)];
+        .allConstructedModelElements[ConstructedModelElementsKey(e, library, enclosingContainer)];
     if (cachedModelElement != null) {
       return cachedModelElement;
     }
@@ -264,7 +264,7 @@ abstract class ModelElement extends Canonicalization

     // Return the cached ModelElement if it exists.
     var cachedModelElement = packageGraph
-        .allConstructedModelElements[(e, library, enclosingContainer)];
+        .allConstructedModelElements[ConstructedModelElementsKey(e, library, enclosingContainer)];
     if (cachedModelElement != null) {
       return cachedModelElement;
     }
@@ -294,11 +294,11 @@ abstract class ModelElement extends Canonicalization
     //                   is fixed?
     if (library != Library.sentinel && newModelElement is! Parameter) {
       runtimeStats.incrementAccumulator('modelElementCacheInsertion');
-      var key = (e, library, enclosingContainer);
+      var key = ConstructedModelElementsKey(e, library, enclosingContainer);
       library.packageGraph.allConstructedModelElements[key] = newModelElement;
       if (newModelElement is Inheritable) {
         library.packageGraph.allInheritableElements
-            .putIfAbsent((e, library), () => {}).add(newModelElement);
+            .putIfAbsent(InheritableElementsKey(e, library), () => {}).add(newModelElement);
       }
     }
   }
diff --git a/lib/src/model/package_graph.dart b/lib/src/model/package_graph.dart
index 71f7baf7..e7e1dbbb 100644
--- a/lib/src/model/package_graph.dart
+++ b/lib/src/model/package_graph.dart
@@ -318,11 +318,11 @@ class PackageGraph with CommentReferable, Nameable, ModelBuilder {

   /// All [ModelElement]s constructed for this package; a superset of
   /// the elements gathered in [_gatherModelElements].
-  final Map<(Element element, Library library, Container? enclosingElement),
-      ModelElement> allConstructedModelElements = {};
+  final Map<ConstructedModelElementsKey, ModelElement>
+      allConstructedModelElements = {};

   /// Anything that might be inheritable, place here for later lookup.
-  final Map<(Element, Library), Set<ModelElement>> allInheritableElements = {};
+  final Map<InheritableElementsKey, Set<ModelElement>> allInheritableElements = {};

   /// A mapping of the list of classes which implement each class.
   final Map<InheritingContainer, List<InheritingContainer>> _implementors =
@@ -800,18 +800,18 @@ class PackageGraph with CommentReferable, Nameable, ModelBuilder {
       {InheritingContainer? preferredClass}) {
     var candidates = <ModelElement>{};
     if (lib != null) {
-      var constructedWithKey = allConstructedModelElements[(e, lib, null)];
+      var constructedWithKey = allConstructedModelElements[ConstructedModelElementsKey(e, lib, null)];
       if (constructedWithKey != null) {
         candidates.add(constructedWithKey);
       }
       var constructedWithKeyWithClass =
-          allConstructedModelElements[(e, lib, preferredClass)];
+          allConstructedModelElements[ConstructedModelElementsKey(e, lib, preferredClass)];
       if (constructedWithKeyWithClass != null) {
         candidates.add(constructedWithKeyWithClass);
       }
       if (candidates.isEmpty) {
         candidates = {
-          ...?allInheritableElements[(e, lib)]?.where((me) => me.isCanonical),
+          ...?allInheritableElements[InheritableElementsKey(e, lib)]?.where((me) => me.isCanonical),
         };
       }
     }
@@ -1004,3 +1004,30 @@ class PackageGraph with CommentReferable, Nameable, ModelBuilder {
   @override
   Iterable<CommentReferable> get referenceParents => const [];
 }
+
+class ConstructedModelElementsKey {
+  final Element element;
+  final Library library;
+  final Container? enclosingElement;
+
+  ConstructedModelElementsKey(
+      this.element, this.library, this.enclosingElement);
+
+  @override
+  late final int hashCode = Object.hash(element, library, enclosingElement);
+
+  @override
+  bool operator ==(Object other) {
+    if (other is! ConstructedModelElementsKey) return false;
+    return other.element == element &&
+        other.library == library &&
+        other.enclosingElement == enclosingElement;
+  }
+}
+
+class InheritableElementsKey {
+  final Element element;
+  final Library library;
+
+  InheritableElementsKey(this.element, this.library);
+}

and the runtime (as reported by the tool itself) went from something like

generateDocs                     22371ms

to something like

generateDocs                     15950ms

--- something along the lines of a 28% improvement in runtime (not that I understand why it has to take that many seconds to generate docs for two almost empty files, but that's besides this particular point).

Important part

(compiling to dill, moving the file, also cp out/ReleaseX64/dart out/ReleaseX64/dart-sdk/bin/, then) Looking at perf report for a perf record -g out/ReleaseX64/dart-sdk/bin/dart --generate_perf_events_symbols pkg/dartdev/bin/dartdev.dill.1 doc /tmp/dartdevFAVRIP/myapp -v run, some things stood out:

30.34%     0.01%  DartWorker       [JIT] tid 303374      [.] CallToRuntime
23.70%     0.51%  DartWorker       [JIT] tid 303374      [.] *dart.collection___Map&_HashVMBase&MapMixin&_HashBase&_OperatorEqualsAndHashCode&_LinkedHashMapMixin@3220832__set@3220832
23.68%     0.33%  DartWorker       [JIT] tid 303374      [.] *dart.collection___Map&_HashVMBase&MapMixin&_HashBase&_OperatorEqualsAndHashCode&_LinkedHashMapMixin@3220832__insert@3220832
23.49%     0.02%  DartWorker       [JIT] tid 303374      [.] *dart.collection___Map&_HashVMBase&MapMixin&_HashBase&_OperatorEqualsAndHashCode&_LinkedHashMapMixin@3220832__rehash@3220832
23.09%     0.19%  DartWorker       [JIT] tid 303374      [.] *dart.collection___Map&_HashVMBase&MapMixin&_HashBase&_OperatorEqualsAndHashCode&_LinkedHashMapMixin@3220832__init@3220832
22.23%     0.01%  DartWorker       dart                  [.] dart::DRT_TypeCheck(dart::NativeArguments)
22.08%     0.02%  DartWorker       [JIT] tid 303374      [.] SlowTypeTest 
21.87%     0.01%  DartWorker       dart                  [.] dart::TypeTestingStubGenerator::SpecializeStubFor(dart::Thread*, dart::AbstractType const&)

(there might be more, who knows).

after the patch, CallToRuntime is 10.79%, all the hash map stuff is <2%, DRT_TypeCheck is 0.34%, SlowTypeTest is 0.14% and SpecializeStubFor is 0.33%.

Interestingly, doing an aot-snapshot there's ~no difference in the runtimes, so this is appears to be a jit-only issue.

jensjoha commented 8 months ago

/cc @mraleph

srawlins commented 8 months ago

Thanks for the great analysis, @jensjoha! The gardeners had noticed this test taking a long time as well, and filed https://github.com/dart-lang/sdk/issues/53278, which I have not looked at in a while. I'll land the dartdoc change and watch this bot.