merge

Author: kenzieschmoll

analysis_options.yaml

@@ -166,8 +166,6 @@ dart_code_metrics:
       - integration_test/**
       # Investigate internal usages of inspector_controller before removing.
       - lib/src/screens/inspector/**_controller.dart
-      - lib/src/extensions/**
-      - lib/src/framework/**
       - lib/src/service/**
       - lib/src/shared/**
       - lib/src/standalone_ui/**

packages/devtools_app/lib/src/framework/home_screen.dart

@@ -171,7 +171,7 @@ class _ConnectInputState extends State<ConnectInput> with BlockingActionMixin {
     // developers who tend to repeatedly restart DevTools to debug the same
     // test application.
     final uri = await storage.getValue(_debugVmServiceUriKey);
-    if (uri != null) {
+    if (uri != null && mounted) {
       setState(() {
         connectDialogController.text = uri;
       });
@@ -253,10 +253,9 @@ class _ConnectInputState extends State<ConnectInput> with BlockingActionMixin {
       return;
     }
 
-    assert(() {
+    if (kDebugMode) {
       safeUnawaited(storage.setValue(_debugVmServiceUriKey, uri));
-      return true;
-    }());
+    }
 
     // Cache the routerDelegate and notifications providers before the async
     // gap as the landing screen may not be displayed by the time the async gap

packages/devtools_app/lib/src/screens/logging/logging_controller.dart

@@ -233,6 +233,13 @@ class LoggingController extends DevToolsScreenController
 
   late final LogDetailsController logDetailsController;
 
+  /// Tracks the previous cumulative GC times (in seconds) for each active isolate.
+  ///
+  /// This is used to compute the actual duration of the current GC event (by taking
+  /// the delta between consecutive cumulative times), rather than displaying the
+  /// total cumulative GC time.
+  final _previousGcTimesByIsolate = <String, double>{};
+
   List<LogData> data = <LogData>[];
 
   final selectedLog = ValueNotifier<LogData?>(null);
@@ -281,6 +288,7 @@ class LoggingController extends DevToolsScreenController
 
   void clear() {
     _updateData([]);
+    _previousGcTimesByIsolate.clear();
     serviceConnection.errorBadgeManager.clearErrorCount(LoggingScreen.id);
   }
 
@@ -448,11 +456,24 @@ class LoggingController extends DevToolsScreenController
     final usedBytes = newSpace.used! + oldSpace.used!;
     final capacityBytes = newSpace.capacity! + oldSpace.capacity!;
 
-    final time = ((newSpace.time! + oldSpace.time!) * 1000).round();
+    final isolateId = e.isolate?.id;
+    // Cumulative time, in seconds.
+    final newCumulativeTime = newSpace.time! + oldSpace.time!;
+
+    String durationText = '';
+    if (isolateId != null) {
+      final previousGcTime = _previousGcTimesByIsolate[isolateId];
+      _previousGcTimesByIsolate[isolateId] = newCumulativeTime;
+      if (previousGcTime != null && newCumulativeTime >= previousGcTime) {
+        // Multiply by 1000 to display in milliseconds.
+        final durationMs = (newCumulativeTime - previousGcTime) * 1000;
+        durationText = ' in ${durationMs.toStringAsFixed(1)} ms';
+      }
+    }
 
     final summary =
         '${isolateRef['name']} • '
-        '${e.json!['reason']} collection in $time ms • '
+        '${e.json!['reason']} collection$durationText • '
         '${printBytes(usedBytes, unit: ByteUnit.mb, includeUnit: true)} used of '
         '${printBytes(capacityBytes, unit: ByteUnit.mb, includeUnit: true)}';
 

packages/devtools_app/release_notes/NEXT_RELEASE_NOTES.md

@@ -45,7 +45,8 @@ TODO: Remove this section if there are not any updates.
 
 ## Logging updates
 
-TODO: Remove this section if there are not any updates.
+* Correct time units and cumulative nature of GC events.
+  [#9890](https://github.com/flutter/devtools/pull/9890)
 
 ## App size tool updates
 

packages/devtools_app/test/screens/logging/logging_controller_test.dart

@@ -19,6 +19,42 @@ import 'package:vm_service/vm_service.dart';
 void main() {
   var timestampCounter = 0;
 
+  Event gcEvent({
+    required double newTime,
+    required double oldTime,
+    required String isolateId,
+  }) => Event.parse({
+    'kind': EventKind.kGC,
+    'timestamp': ++timestampCounter,
+    'isolate': {
+      'type': '@Isolate',
+      'id': isolateId,
+      'name': 'main',
+      'number': '1',
+    },
+    'reason': 'idle',
+    'new': {
+      'type': 'HeapSpace',
+      'name': 'new',
+      'collections': 1,
+      'avgCollectionPeriodMillis': 100.0,
+      'used': 1024,
+      'capacity': 2048,
+      'external': 0,
+      'time': newTime,
+    },
+    'old': {
+      'type': 'HeapSpace',
+      'name': 'old',
+      'collections': 1,
+      'avgCollectionPeriodMillis': 100.0,
+      'used': 4096,
+      'capacity': 8192,
+      'external': 0,
+      'time': oldTime,
+    },
+  })!;
+
   group('LoggingController', () {
     late LoggingController controller;
 
@@ -194,6 +230,94 @@ void main() {
       expect(controller.filteredData.value, isEmpty);
     });
 
+    test('GC events track duration delta', () async {
+      final fakeService =
+          serviceConnection.serviceManager.service as FakeVmServiceWrapper;
+
+      expect(controller.data, isEmpty);
+
+      // First GC event: baseline established, no duration printed.
+      fakeService.emitGCEvent(
+        event: gcEvent(newTime: 0.1, oldTime: 0.2, isolateId: 'isolates/123'),
+      );
+      await Future<void>.delayed(const Duration(milliseconds: 10));
+
+      expect(controller.data, hasLength(1));
+      expect(
+        controller.data.first.summary,
+        'main • idle collection • 0.0 MB used of 0.0 MB',
+      );
+
+      // Second GC event: delta is
+      // (0.15 + 0.25) - (0.1 + 0.2) = 0.4 - 0.3 = 0.1s = 100ms.
+      fakeService.emitGCEvent(
+        event: gcEvent(newTime: 0.15, oldTime: 0.25, isolateId: 'isolates/123'),
+      );
+      await Future<void>.delayed(const Duration(milliseconds: 10));
+
+      expect(controller.data, hasLength(2));
+      expect(
+        controller.data[1].summary,
+        'main • idle collection in 100.0 ms • 0.0 MB used of 0.0 MB',
+      );
+
+      // Third GC event on a different isolate: no baseline yet, so no duration
+      // printed.
+      fakeService.emitGCEvent(
+        event: gcEvent(newTime: 0.05, oldTime: 0.05, isolateId: 'isolates/456'),
+      );
+      await Future<void>.delayed(const Duration(milliseconds: 10));
+
+      expect(controller.data, hasLength(3));
+      expect(
+        controller.data[2].summary,
+        'main • idle collection • 0.0 MB used of 0.0 MB',
+      );
+
+      // Fourth GC event: clock reset on isolates/123 (cumulative goes from 0.4s to 0.1s).
+      // Since newCumulativeTime (0.1s) < previousGcTime (0.4s), duration delta is skipped,
+      // and baseline is updated to 0.1s.
+      fakeService.emitGCEvent(
+        event: gcEvent(newTime: 0.05, oldTime: 0.05, isolateId: 'isolates/123'),
+      );
+      await Future<void>.delayed(const Duration(milliseconds: 10));
+
+      expect(controller.data, hasLength(4));
+      expect(
+        controller.data[3].summary,
+        'main • idle collection • 0.0 MB used of 0.0 MB',
+      );
+
+      // Fifth GC event: delta since reset baseline (0.1s) is (0.08 + 0.12) - 0.1 = 0.2 - 0.1 = 0.1s = 100ms.
+      fakeService.emitGCEvent(
+        event: gcEvent(newTime: 0.08, oldTime: 0.12, isolateId: 'isolates/123'),
+      );
+      await Future<void>.delayed(const Duration(milliseconds: 10));
+
+      expect(controller.data, hasLength(5));
+      expect(
+        controller.data[4].summary,
+        'main • idle collection in 100.0 ms • 0.0 MB used of 0.0 MB',
+      );
+
+      // Clear logs: resets baselines.
+      controller.clear();
+      expect(controller.data, isEmpty);
+
+      // Sixth GC event (same isolate as first): baseline was cleared, so no
+      // duration printed.
+      fakeService.emitGCEvent(
+        event: gcEvent(newTime: 0.2, oldTime: 0.3, isolateId: 'isolates/123'),
+      );
+      await Future<void>.delayed(const Duration(milliseconds: 10));
+
+      expect(controller.data, hasLength(1));
+      expect(
+        controller.data.first.summary,
+        'main • idle collection • 0.0 MB used of 0.0 MB',
+      );
+    });
+
     test('matchesForSearch - default filters', () {
       prepareTestLogs();
 

packages/devtools_test/lib/src/mocks/fake_vm_service_wrapper.dart

@@ -128,30 +128,25 @@ class FakeVmServiceWrapper extends Fake implements VmServiceWrapper {
   }
 
   @override
-  Future<UriList> lookupPackageUris(String isolateId, List<String> uris) {
-    return Future.value(
-      UriList(
-        uris: _resolvedUriMap != null
-            ? (uris.map((e) => _resolvedUriMap[e]).toList())
-            : null,
-      ),
-    );
-  }
+  Future<UriList> lookupPackageUris(
+    String isolateId,
+    List<String> uris,
+  ) => Future.syncValue(UriList(
+    uris: _resolvedUriMap != null
+        ? (uris.map((e) => _resolvedUriMap[e]).toList())
+        : null
+  ));
 
   @override
   Future<UriList> lookupResolvedPackageUris(
     String isolateId,
     List<String> uris, {
     bool? local,
-  }) {
-    return Future.value(
-      UriList(
-        uris: _reverseResolvedUriMap != null
-            ? (uris.map((e) => _reverseResolvedUriMap[e]).toList())
-            : null,
-      ),
-    );
-  }
+  })  => Future.syncValue(UriList(
+    uris: _reverseResolvedUriMap != null
+        ? (uris.map((e) => _reverseResolvedUriMap[e]).toList())
+        : null,
+  ));
 
   @override
   String get wsUri => 'ws://127.0.0.1:56137/ISsyt6ki0no=/ws';
@@ -190,14 +185,14 @@ class FakeVmServiceWrapper extends Fake implements VmServiceWrapper {
     allocationProfile.json = allocationProfile.toJson();
     // Fake GC statistics
     allocationProfile.json![AllocationProfilePrivateViewExtension.heapsKey] =
-        <String, dynamic>{
-          AllocationProfilePrivateViewExtension.newSpaceKey: <String, dynamic>{
+        <String, Object?>{
+          AllocationProfilePrivateViewExtension.newSpaceKey: <String, Object?>{
             GCStats.usedKey: 1234,
             GCStats.capacityKey: 12345,
             GCStats.collectionsKey: 42,
             GCStats.timeKey: 69,
           },
-          AllocationProfilePrivateViewExtension.oldSpaceKey: <String, dynamic>{
+          AllocationProfilePrivateViewExtension.oldSpaceKey: <String, Object?>{
             GCStats.usedKey: 4321,
             GCStats.capacityKey: 54321,
             GCStats.collectionsKey: 24,
@@ -522,8 +517,8 @@ class FakeVmServiceWrapper extends Fake implements VmServiceWrapper {
   @override
   Stream<Event> get onGCEvent => _gcEventStream.stream;
 
-  void emitGCEvent() {
-    _gcEventStream.sink.add(Event(kind: EventKind.kGC));
+  void emitGCEvent({Event? event}) {
+    _gcEventStream.sink.add(event ?? Event(kind: EventKind.kGC));
   }
 
   @override