Print events and views when first frame is taking awhile during tracing (#98957)
diff --git a/packages/flutter_tools/lib/src/tracing.dart b/packages/flutter_tools/lib/src/tracing.dart
index 8b35765..c896a2b 100644
--- a/packages/flutter_tools/lib/src/tracing.dart
+++ b/packages/flutter_tools/lib/src/tracing.dart
@@ -51,7 +51,10 @@
// 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 @@
}
}
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 3d654c4..fb885f8 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 @@
), 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<void> completer = Completer<void>();
+ await FakeAsync().run((FakeAsync time) {
+ final Map<String, String> extensionData = <String, String>{
+ 'test': 'data',
+ 'renderedErrorText': 'error text',
+ };
+ final FakeVmServiceHost fakeVmServiceHost = FakeVmServiceHost(requests: <VmServiceExpectation>[
+ const FakeVmServiceRequest(
+ method: 'streamListen',
+ args: <String, Object>{
+ 'streamId': vm_service.EventKind.kExtension,
+ }
+ ),
+ const FakeVmServiceRequest(
+ method: kListViewsMethod,
+ jsonResponse: <String, Object>{
+ 'views': <Object>[
+ <String, Object?>{
+ '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();
