From 535e88b092838ac628232b19bb4728e17efc08ed Mon Sep 17 00:00:00 2001 From: Andrew Kolos Date: Wed, 31 Jul 2024 16:15:17 -0700 Subject: [PATCH] Reintroduce verbose logging for hot reload flake (#152639) Adds some logging to assist with troubleshooting https://github.com/flutter/flutter/issues/152220 (which is a reapperance of flake https://github.com/flutter/flutter/issues/146879) on CI. TL;DR [the tool sometimes never receives the `IsolateRunnable` event from the vm service after calling `_flutter.runInView`](https://github.com/flutter/flutter/issues/146879#issuecomment-2118629953). --- packages/flutter_tools/lib/src/run_hot.dart | 9 --------- packages/flutter_tools/lib/src/vmservice.dart | 20 +++++++++++++++++++ .../test/general.shard/vmservice_test.dart | 2 +- 3 files changed, 21 insertions(+), 10 deletions(-) diff --git a/packages/flutter_tools/lib/src/run_hot.dart b/packages/flutter_tools/lib/src/run_hot.dart index 2684e093b56..c73e578df0e 100644 --- a/packages/flutter_tools/lib/src/run_hot.dart +++ b/packages/flutter_tools/lib/src/run_hot.dart @@ -643,14 +643,6 @@ class HotRunner extends ResidentRunner { final Future reloadIsolate = device.vmService! .getIsolateOrNull(view.uiIsolate!.id!); operations.add(reloadIsolate.then((vm_service.Isolate? isolate) async { - // TODO(andrewkolos): this race is meant to assist in debugging - // https://github.com/flutter/flutter/issues/145812. When the issue - // is resolved, this trace (and probably all others added by - // the same PR) can be removed. - globals.logger.printTrace( - 'Beginning of UI start paused handler. ' - 'uiIsolate = $isolate; isolate.pauseEvent.kind = ${isolate?.pauseEvent!.kind}', - ); if ((isolate != null) && isPauseEvent(isolate.pauseEvent!.kind!)) { // The embedder requires that the isolate is unpaused, because the // runInView method requires interaction with dart engine APIs that @@ -673,7 +665,6 @@ class HotRunner extends ResidentRunner { await Future.wait(breakpointAndExceptionRemoval); await device.vmService!.service.resume(view.uiIsolate!.id!); } - globals.logger.printTrace('End of UI start paused handler.'); })); } diff --git a/packages/flutter_tools/lib/src/vmservice.dart b/packages/flutter_tools/lib/src/vmservice.dart index 196994c8b36..df5c969f42b 100644 --- a/packages/flutter_tools/lib/src/vmservice.dart +++ b/packages/flutter_tools/lib/src/vmservice.dart @@ -578,6 +578,25 @@ class FlutterVmService { } } + // TODO(andrewkolos): this is to assist in troubleshooting + // https://github.com/flutter/flutter/issues/152220 and should be reverted + // once this issue is resolved. + final StreamSubscription onReceiveSubscription = service.onReceive.listen( + (String message) { + globals.logger.printTrace( + 'runInView VM service onReceive listener received "$message"', + ); + final dynamic messageAsJson = jsonDecode(message); + // ignore: avoid_dynamic_calls -- Temporary code. + final dynamic messageKind = messageAsJson['params']?['event']?['kind']; + if (messageKind == 'IsolateRunnable') { + globals.logger.printTrace( + 'Received IsolateRunnable event from onReceive.', + ); + } + }, + ); + final Future onRunnable = service.onIsolateEvent.firstWhere((vm_service.Event event) { return event.kind == vm_service.EventKind.kIsolateRunnable; }); @@ -590,6 +609,7 @@ class FlutterVmService { }, ); await onRunnable; + await onReceiveSubscription.cancel(); } Future flutterDebugDumpApp({ diff --git a/packages/flutter_tools/test/general.shard/vmservice_test.dart b/packages/flutter_tools/test/general.shard/vmservice_test.dart index 951529364f3..683ebeef75e 100644 --- a/packages/flutter_tools/test/general.shard/vmservice_test.dart +++ b/packages/flutter_tools/test/general.shard/vmservice_test.dart @@ -231,7 +231,7 @@ void main() { }); }); - testWithoutContext('runInView forwards arguments correctly', () async { + testUsingContext('runInView forwards arguments correctly', () async { final FakeVmServiceHost fakeVmServiceHost = FakeVmServiceHost( requests: [ const FakeVmServiceRequest(method: 'streamListen', args: {