diff --git a/packages/flutter_tools/lib/src/tracing.dart b/packages/flutter_tools/lib/src/tracing.dart index 8b357650582..c896a2b9011 100644 --- a/packages/flutter_tools/lib/src/tracing.dart +++ b/packages/flutter_tools/lib/src/tracing.dart @@ -51,7 +51,10 @@ class Tracing { // It is safe to ignore this error because we expect an error to be // thrown if we're already subscribed. } + final StringBuffer bufferedEvents = StringBuffer(); + void Function(String) handleBufferedEvent = bufferedEvents.writeln; vmService.service.onExtensionEvent.listen((vm_service.Event event) { + handleBufferedEvent('${event.extensionKind}: ${event.extensionData}'); if (event.extensionKind == 'Flutter.FirstFrame') { whenFirstFrameRendered.complete(); } @@ -69,7 +72,19 @@ class Tracing { } } if (!done) { + final Timer timer = Timer(const Duration(seconds: 10), () { + _logger.printStatus('First frame is taking longer than expected...'); + _logger.printTrace('Views:'); + for (final FlutterView view in views) { + _logger.printTrace('id: ${view.id} isolate: ${view.uiIsolate?.id}'); + } + _logger.printTrace('Received VM events:'); + _logger.printTrace(bufferedEvents.toString()); + // Swap to just printing new events instead of buffering. + handleBufferedEvent = _logger.printTrace; + }); await whenFirstFrameRendered.future; + timer.cancel(); } // The exception is rethrown, so don't catch only Exceptions. } catch (exception) { // ignore: avoid_catches_without_on_clauses diff --git a/packages/flutter_tools/test/general.shard/tracing_test.dart b/packages/flutter_tools/test/general.shard/tracing_test.dart index 3d654c4a419..fb885f8d42a 100644 --- a/packages/flutter_tools/test/general.shard/tracing_test.dart +++ b/packages/flutter_tools/test/general.shard/tracing_test.dart @@ -2,6 +2,9 @@ // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. +import 'dart:async'; + +import 'package:fake_async/fake_async.dart'; import 'package:file/memory.dart'; import 'package:file_testing/file_testing.dart'; import 'package:flutter_tools/src/base/file_system.dart'; @@ -181,6 +184,58 @@ void main() { ), throwsToolExit(message: 'Engine start event is missing in the timeline')); }); + testWithoutContext('prints when first frame is taking a long time', () async { + final BufferLogger logger = BufferLogger.test(); + final FileSystem fileSystem = MemoryFileSystem.test(); + final Completer completer = Completer(); + await FakeAsync().run((FakeAsync time) { + final Map extensionData = { + 'test': 'data', + 'renderedErrorText': 'error text', + }; + final FakeVmServiceHost fakeVmServiceHost = FakeVmServiceHost(requests: [ + const FakeVmServiceRequest( + method: 'streamListen', + args: { + 'streamId': vm_service.EventKind.kExtension, + } + ), + const FakeVmServiceRequest( + method: kListViewsMethod, + jsonResponse: { + 'views': [ + { + 'id': '1', + // No isolate, no views. + 'isolate': null, + } + ], + }, + ), + FakeVmServiceStreamResponse( + streamId: 'Extension', + event: vm_service.Event( + timestamp: 0, + extensionKind: 'Flutter.Error', + extensionData: vm_service.ExtensionData.parse(extensionData), + kind: vm_service.EventStreams.kExtension, + ), + ), + ]); + unawaited(downloadStartupTrace(fakeVmServiceHost.vmService, + output: fileSystem.currentDirectory, + logger: logger, + )); + time.elapse(const Duration(seconds: 11)); + time.flushMicrotasks(); + completer.complete(); + return completer.future; + }); + expect(logger.statusText, contains('First frame is taking longer than expected')); + expect(logger.traceText, contains('id: 1 isolate: null')); + expect(logger.traceText, contains('Flutter.Error: [ExtensionData {test: data, renderedErrorText: error text}]')); + }); + testWithoutContext('throws tool exit if first frame events are missing', () async { final BufferLogger logger = BufferLogger.test(); final FileSystem fileSystem = MemoryFileSystem.test();