[flutter_tools] remove globals from tracing and add unit tests (#65490)

Removes global variables and adds unit tests that can be copied for #65118

packages/flutter_tools/lib/src/run_cold.dart

@@ -7,6 +7,7 @@ import 'dart:async';
 import 'package:meta/meta.dart';
 
 import 'base/file_system.dart';
+import 'build_info.dart';
 import 'device.dart';
 import 'globals.dart' as globals;
 import 'resident_runner.dart';
@@ -117,6 +118,8 @@ class ColdRunner extends ResidentRunner {
         await downloadStartupTrace(
           device.vmService,
           awaitFirstFrame: awaitFirstFrameWhenTracing,
+          logger: globals.logger,
+          output: globals.fs.directory(getBuildDirectory()),
         );
       }
       appFinished();

packages/flutter_tools/lib/src/tracing.dart

@@ -3,13 +3,14 @@
 // found in the LICENSE file.
 
 import 'dart:async';
+import 'package:meta/meta.dart';
 import 'package:vm_service/vm_service.dart' as vm_service;
 
+import 'base/common.dart';
 import 'base/file_system.dart';
 import 'base/logger.dart';
 import 'base/utils.dart';
-import 'build_info.dart';
-import 'globals.dart' as globals;
+
 import 'vmservice.dart';
 
 // Names of some of the Timeline events we care about.
@@ -19,10 +20,15 @@ const String kFirstFrameBuiltEventName = 'Widgets built first useful frame';
 const String kFirstFrameRasterizedEventName = 'Rasterized first useful frame';
 
 class Tracing {
-  Tracing(this.vmService);
+  Tracing({
+    @required this.vmService,
+    @required Logger logger,
+  }) : _logger = logger;
 
   static const String firstUsefulFrameEventName = kFirstFrameRasterizedEventName;
+
   final vm_service.VmService vmService;
+  final Logger _logger;
 
   Future<void> startTracing() async {
     await vmService.setVMTimelineFlags(<String>['Compiler', 'Dart', 'Embedder', 'GC']);
@@ -34,9 +40,9 @@ class Tracing {
     bool awaitFirstFrame = false,
   }) async {
     if (awaitFirstFrame) {
-      final Status status = globals.logger.startProgress(
+      final Status status = _logger.startProgress(
         'Waiting for application to render first frame...',
-        timeout: timeoutConfiguration.fastOperation,
+        timeout: null,
       );
       try {
         final Completer<void> whenFirstFrameRendered = Completer<void>();
@@ -80,9 +86,12 @@ class Tracing {
 
 /// Download the startup trace information from the given observatory client and
 /// store it to build/start_up_info.json.
-Future<void> downloadStartupTrace(vm_service.VmService vmService, { bool awaitFirstFrame = true }) async {
-  final String traceInfoFilePath = globals.fs.path.join(getBuildDirectory(), 'start_up_info.json');
-  final File traceInfoFile = globals.fs.file(traceInfoFilePath);
+Future<void> downloadStartupTrace(vm_service.VmService vmService, {
+  bool awaitFirstFrame = true,
+  @required Logger logger,
+  @required Directory output,
+}) async {
+  final File traceInfoFile = output.childFile('start_up_info.json');
 
   // Delete old startup data, if any.
   if (traceInfoFile.existsSync()) {
@@ -94,7 +103,7 @@ Future<void> downloadStartupTrace(vm_service.VmService vmService, { bool awaitFi
     traceInfoFile.parent.createSync();
   }
 
-  final Tracing tracing = Tracing(vmService);
+  final Tracing tracing = Tracing(vmService: vmService, logger: logger);
 
   final Map<String, dynamic> timeline = await tracing.stopTracingAndDownloadTimeline(
     awaitFirstFrame: awaitFirstFrame,
@@ -115,8 +124,8 @@ Future<void> downloadStartupTrace(vm_service.VmService vmService, { bool awaitFi
   final int frameworkInitTimestampMicros = extractInstantEventTimestamp(kFrameworkInitEventName);
 
   if (engineEnterTimestampMicros == null) {
-    globals.printTrace('Engine start event is missing in the timeline: $timeline');
-    throw 'Engine start event is missing in the timeline. Cannot compute startup time.';
+    logger.printTrace('Engine start event is missing in the timeline: $timeline');
+    throwToolExit('Engine start event is missing in the timeline. Cannot compute startup time.');
   }
 
   final Map<String, dynamic> traceInfo = <String, dynamic>{
@@ -133,8 +142,8 @@ Future<void> downloadStartupTrace(vm_service.VmService vmService, { bool awaitFi
     final int firstFrameBuiltTimestampMicros = extractInstantEventTimestamp(kFirstFrameBuiltEventName);
     final int firstFrameRasterizedTimestampMicros = extractInstantEventTimestamp(kFirstFrameRasterizedEventName);
     if (firstFrameBuiltTimestampMicros == null || firstFrameRasterizedTimestampMicros == null) {
-      globals.printTrace('First frame events are missing in the timeline: $timeline');
-      throw 'First frame events are missing in the timeline. Cannot compute startup time.';
+      logger.printTrace('First frame events are missing in the timeline: $timeline');
+      throwToolExit('First frame events are missing in the timeline. Cannot compute startup time.');
     }
 
     // To keep our old benchmarks valid, we'll preserve the
@@ -152,6 +161,6 @@ Future<void> downloadStartupTrace(vm_service.VmService vmService, { bool awaitFi
 
   traceInfoFile.writeAsStringSync(toPrettyJson(traceInfo));
 
-  globals.printStatus(message);
-  globals.printStatus('Saved startup trace info in ${traceInfoFile.path}.');
+  logger.printStatus(message);
+  logger.printStatus('Saved startup trace info in ${traceInfoFile.path}.');
 }

packages/flutter_tools/test/general.shard/tracing_test.dart

+// Copyright 2014 The Flutter Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+import 'package:file/memory.dart';
+import 'package:file_testing/file_testing.dart';
+import 'package:flutter_tools/src/base/file_system.dart';
+import 'package:flutter_tools/src/base/logger.dart';
+import 'package:flutter_tools/src/convert.dart';
+import 'package:flutter_tools/src/tracing.dart';
+import 'package:flutter_tools/src/vmservice.dart';
+import 'package:vm_service/vm_service.dart' as vm_service;
+
+import '../src/common.dart';
+
+final vm_service.Isolate fakeUnpausedIsolate = vm_service.Isolate(
+  id: '1',
+  pauseEvent: vm_service.Event(
+    kind: vm_service.EventKind.kResume,
+    timestamp: 0
+  ),
+  breakpoints: <vm_service.Breakpoint>[],
+  exceptionPauseMode: null,
+  libraries: <vm_service.LibraryRef>[
+    vm_service.LibraryRef(
+      id: '1',
+      uri: 'file:///hello_world/main.dart',
+      name: '',
+    ),
+  ],
+  livePorts: 0,
+  name: 'test',
+  number: '1',
+  pauseOnExit: false,
+  runnable: true,
+  startTime: 0,
+);
+
+final FlutterView fakeFlutterView = FlutterView(
+  id: 'a',
+  uiIsolate: fakeUnpausedIsolate,
+);
+
+final FakeVmServiceRequest listViews = FakeVmServiceRequest(
+  method: kListViewsMethod,
+  jsonResponse: <String, Object>{
+    'views': <Object>[
+      fakeFlutterView.toJson(),
+    ],
+  },
+);
+
+final List<FakeVmServiceRequest> vmServiceSetup = <FakeVmServiceRequest>[
+  const FakeVmServiceRequest(
+    method: 'streamListen',
+    args: <String, Object>{
+      'streamId': vm_service.EventKind.kExtension,
+    }
+  ),
+  listViews,
+  // Satisfies didAwaitFirstFrame
+  const FakeVmServiceRequest(
+    method: 'ext.flutter.didSendFirstFrameRasterizedEvent',
+    args: <String, Object>{
+      'isolateId': '1',
+    },
+    jsonResponse: <String, Object>{
+      'enabled': 'true'
+    },
+  ),
+];
+
+void main() {
+  testWithoutContext('Can trace application startup', () async {
+    final BufferLogger logger = BufferLogger.test();
+    final FileSystem fileSystem = MemoryFileSystem.test();
+    final FakeVmServiceHost fakeVmServiceHost = FakeVmServiceHost(requests: <FakeVmServiceRequest>[
+      ...vmServiceSetup,
+      FakeVmServiceRequest(
+        method: 'getVMTimeline',
+        jsonResponse: vm_service.Timeline(
+          timeExtentMicros: 4,
+          timeOriginMicros: 0,
+          traceEvents: <vm_service.TimelineEvent>[
+            vm_service.TimelineEvent.parse(<String, Object>{
+              'name': kFlutterEngineMainEnterEventName,
+              'ts': 0,
+            }),
+            vm_service.TimelineEvent.parse(<String, Object>{
+              'name': kFrameworkInitEventName,
+              'ts': 1,
+            }),
+            vm_service.TimelineEvent.parse(<String, Object>{
+              'name': kFirstFrameBuiltEventName,
+              'ts': 2,
+            }),
+            vm_service.TimelineEvent.parse(<String, Object>{
+              'name': kFirstFrameRasterizedEventName,
+              'ts': 3,
+            }),
+          ],
+        ).toJson(),
+      ),
+      const FakeVmServiceRequest(
+        method: 'setVMTimelineFlags',
+        args: <String, Object>{
+          'recordedStreams': <Object>[],
+        },
+      ),
+    ]);
+
+    // Validate that old tracing data is deleted.
+    final File outFile = fileSystem.currentDirectory.childFile('start_up_info.json')
+      ..writeAsStringSync('stale');
+
+    await downloadStartupTrace(fakeVmServiceHost.vmService,
+      output: fileSystem.currentDirectory,
+      logger: logger,
+    );
+
+    expect(outFile, exists);
+    expect(json.decode(outFile.readAsStringSync()), <String, Object>{
+      'engineEnterTimestampMicros': 0,
+      'timeToFrameworkInitMicros': 1,
+      'timeToFirstFrameRasterizedMicros': 3,
+      'timeToFirstFrameMicros': 2,
+      'timeAfterFrameworkInitMicros': 1,
+    });
+  });
+
+  testWithoutContext('throws tool exit if timeline is missing the engine start event', () async {
+    final BufferLogger logger = BufferLogger.test();
+    final FileSystem fileSystem = MemoryFileSystem.test();
+    final FakeVmServiceHost fakeVmServiceHost = FakeVmServiceHost(requests: <FakeVmServiceRequest>[
+      ...vmServiceSetup,
+      FakeVmServiceRequest(
+        method: 'getVMTimeline',
+        jsonResponse: vm_service.Timeline(
+          timeExtentMicros: 4,
+          timeOriginMicros: 0,
+          traceEvents: <vm_service.TimelineEvent>[],
+        ).toJson(),
+      ),
+      const FakeVmServiceRequest(
+        method: 'setVMTimelineFlags',
+        args: <String, Object>{
+          'recordedStreams': <Object>[],
+        },
+      ),
+    ]);
+
+    await expectLater(() async => await downloadStartupTrace(fakeVmServiceHost.vmService,
+      output: fileSystem.currentDirectory,
+      logger: logger,
+    ), throwsToolExit(message: 'Engine start event is missing in the timeline'));
+  });
+
+  testWithoutContext('throws tool exit if first frame events are missing', () async {
+    final BufferLogger logger = BufferLogger.test();
+    final FileSystem fileSystem = MemoryFileSystem.test();
+    final FakeVmServiceHost fakeVmServiceHost = FakeVmServiceHost(requests: <FakeVmServiceRequest>[
+      ...vmServiceSetup,
+      FakeVmServiceRequest(
+        method: 'getVMTimeline',
+        jsonResponse: vm_service.Timeline(
+          timeExtentMicros: 4,
+          timeOriginMicros: 0,
+          traceEvents: <vm_service.TimelineEvent>[
+            vm_service.TimelineEvent.parse(<String, Object>{
+              'name': kFlutterEngineMainEnterEventName,
+              'ts': 0,
+            }),
+            vm_service.TimelineEvent.parse(<String, Object>{
+              'name': kFrameworkInitEventName,
+              'ts': 1,
+            }),
+          ],
+        ).toJson(),
+      ),
+      const FakeVmServiceRequest(
+        method: 'setVMTimelineFlags',
+        args: <String, Object>{
+          'recordedStreams': <Object>[],
+        },
+      ),
+    ]);
+
+    await expectLater(() async => await downloadStartupTrace(fakeVmServiceHost.vmService,
+      output: fileSystem.currentDirectory,
+      logger: logger,
+    ), throwsToolExit(message: 'First frame events are missing in the timeline'));
+  });
+
+  testWithoutContext('Can trace application startup without awaiting for first frame', () async {
+    final BufferLogger logger = BufferLogger.test();
+    final FileSystem fileSystem = MemoryFileSystem.test();
+    final FakeVmServiceHost fakeVmServiceHost = FakeVmServiceHost(requests: <FakeVmServiceRequest>[
+      FakeVmServiceRequest(
+        method: 'getVMTimeline',
+        jsonResponse: vm_service.Timeline(
+          timeExtentMicros: 4,
+          timeOriginMicros: 0,
+          traceEvents: <vm_service.TimelineEvent>[
+            vm_service.TimelineEvent.parse(<String, Object>{
+              'name': kFlutterEngineMainEnterEventName,
+              'ts': 0,
+            }),
+            vm_service.TimelineEvent.parse(<String, Object>{
+              'name': kFrameworkInitEventName,
+              'ts': 1,
+            }),
+          ],
+        ).toJson(),
+      ),
+      const FakeVmServiceRequest(
+        method: 'setVMTimelineFlags',
+        args: <String, Object>{
+          'recordedStreams': <Object>[],
+        },
+      ),
+    ]);
+
+    final File outFile = fileSystem.currentDirectory.childFile('start_up_info.json');
+
+    await downloadStartupTrace(fakeVmServiceHost.vmService,
+      output: fileSystem.currentDirectory,
+      logger: logger,
+      awaitFirstFrame: false,
+    );
+
+    expect(outFile, exists);
+    expect(json.decode(outFile.readAsStringSync()), <String, Object>{
+      'engineEnterTimestampMicros': 0,
+      'timeToFrameworkInitMicros': 1,
+    });
+  });
+}