Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Mac_arm64_ios hot_mode_dev_cycle_ios__benchmark errors on hot restart/hot reload #142305

Open
vashworth opened this issue Jan 26, 2024 · 21 comments
Open

Mac_arm64_ios hot_mode_dev_cycle_ios__benchmark errors on hot restart/hot reload #142305

vashworth opened this issue Jan 26, 2024 · 21 comments
Labels
c: flake Tests that sometimes, but not always, incorrectly pass dependency:dart-triaged Triaged by Dart team P2 Important issues not at the top of the work list team-tool Owned by Flutter Tool team tool Affects the "flutter" command-line tool. See also t: labels. triaged-tool Triaged by Flutter Tool team

Comments

@vashworth
Copy link
Contributor

vashworth commented Jan 26, 2024 •
edited

https://ci.chromium.org/ui/p/flutter/builders/staging/Mac_arm64_ios%20hot_mode_dev_cycle_ios__benchmark/44/overview
https://ci.chromium.org/ui/p/flutter/builders/staging/Mac_arm64_ios%20hot_mode_dev_cycle_ios__benchmark/57/overview
https://ci.chromium.org/ui/p/flutter/builders/staging/Mac_arm64_ios%20hot_mode_dev_cycle_ios__benchmark/27/overview
https://ci.chromium.org/ui/p/flutter/builders/staging/Mac_arm64_ios%20hot_mode_dev_cycle_ios__benchmark/23/overview
https://ci.chromium.org/ui/p/flutter/builders/staging/Mac_arm64_ios%20hot_mode_dev_cycle_ios__benchmark/12/overview

 [2024-01-26 05:50:06.761587] [STDOUT] stdout: [        ] Performing hot restart...
 [2024-01-26 05:50:06.771117] [STDOUT] stdout: [   +9 ms] Scanned through 728 files in 8ms
 [2024-01-26 05:50:06.771208] [STDOUT] stdout: [        ] Syncing files to device swarming’s iPhone...
 [2024-01-26 05:50:06.772572] [STDOUT] stdout: [   +1 ms] <- reset
 [2024-01-26 05:50:06.772621] [STDOUT] stdout: [        ] Compiling dart to kernel with 1 updated files
 [2024-01-26 05:50:06.772657] [STDOUT] stdout: [        ] Processing bundle.
 [2024-01-26 05:50:06.772754] [STDOUT] stdout: [        ] <- recompile package:flutter_gallery/main.dart 369c601b-9e95-46fa-8539-43fbf355cd80
 [2024-01-26 05:50:06.772840] [STDOUT] stdout: [        ] file:///opt/s/w/ir/x/t/edited_flutter_gallery/.dart_tool/flutter_build/dart_plugin_registrant.dart
 [2024-01-26 05:50:06.772854] [STDOUT] stdout: [        ] <- 369c601b-9e95-46fa-8539-43fbf355cd80
 [2024-01-26 05:50:06.774174] [STDOUT] stdout: [   +1 ms] Bundle processing done.
 [2024-01-26 05:50:06.804430] [STDOUT] stdout: [  +30 ms] Updating files.
 [2024-01-26 05:50:07.164176] [STDOUT] stderr: ERROR - 2024-01-26 05:50:07.163999
 [2024-01-26 05:50:07.164218] [STDOUT] stderr: PUT /cvAGasOHVbU=/
 [2024-01-26 05:50:07.164229] [STDOUT] stderr: Error thrown by handler.
 [2024-01-26 05:50:07.164237] [STDOUT] stderr: Connection reset by peer
 [2024-01-26 05:50:07.167345] [STDOUT] stderr: package:shelf/shelf_io.dart 138:16  handleRequest
 [2024-01-26 05:50:07.167363] [STDOUT] stderr: 
 [2024-01-26 05:50:07.169786] [STDOUT] stdout: [ +365 ms] DevFS: Sync finished
 [2024-01-26 05:50:07.169830] [STDOUT] stdout: [        ] Syncing files to device swarming’s iPhone... (completed in 398ms)
 [2024-01-26 05:50:07.169927] [STDOUT] stdout: [        ] Synced 40.5MB.
 [2024-01-26 05:50:07.170006] [STDOUT] stdout: [        ] <- accept
 [2024-01-26 05:50:07.200064] [STDOUT] stdout: [  +30 ms] [ERROR:flutter/shell/common/shell.cc(117)] Dart Error: Can't load Kernel binary: Invalid kernel binary: Indicated size is invalid.
 [2024-01-26 05:50:07.200129] [STDOUT] stdout: [        ] [ERROR:flutter/runtime/dart_isolate.cc(144)] Could not prepare isolate.
 [2024-01-26 05:50:07.202566] [STDOUT] stdout: [   +2 ms] Performing hot restart... (completed in 440ms)
 [2024-01-26 05:50:07.202612] [STDOUT] stdout: [        ] Restarted application in 507ms.
 [2024-01-26 05:50:07.223161] [STDOUT] stdout: [  +20 ms] [ERROR:flutter/runtime/runtime_controller.cc(462)] Could not create root isolate.
 [2024-01-26 05:50:17.207130] [STDOUT] stdout: [+9983 ms] Benchmarking hot reload
 [2024-01-26 05:50:17.209449] [STDOUT] stdout: [   +2 ms] Skipping target: gen_localizations
 [2024-01-26 05:50:17.210670] [STDOUT] stdout: [   +1 ms] Skipping target: gen_dart_plugin_registrant
 [2024-01-26 05:50:17.210843] [STDOUT] stdout: [        ] Skipping target: _composite
 [2024-01-26 05:50:17.210992] [STDOUT] stdout: [        ] complete
 [2024-01-26 05:50:17.212366] [STDOUT] stdout: [   +1 ms] Performing hot reload...
 [2024-01-26 05:50:17.239280] [STDOUT] stdout: [  +26 ms] Scanned through 728 files in 18ms
 [2024-01-26 05:50:17.239584] [STDOUT] stdout: [        ] Syncing files to device swarming’s iPhone...
 [2024-01-26 05:50:17.243269] [STDOUT] stdout: [   +3 ms] Compiling dart to kernel with 0 updated files
 [2024-01-26 05:50:17.243387] [STDOUT] stdout: [        ] Processing bundle.
 [2024-01-26 05:50:17.243587] [STDOUT] stdout: [        ] <- recompile package:flutter_gallery/main.dart 03b92394-653e-4781-9d77-a8ea64667fb4
 [2024-01-26 05:50:17.243665] [STDOUT] stdout: [        ] <- 03b92394-653e-4781-9d77-a8ea64667fb4
 [2024-01-26 05:50:17.246260] [STDOUT] stdout: [   +2 ms] Bundle processing done.
 [2024-01-26 05:50:17.257259] [STDOUT] stdout: [  +10 ms] Updating files.
 [2024-01-26 05:50:17.294994] [STDOUT] stdout: [  +37 ms] DevFS: Sync finished
 [2024-01-26 05:50:17.295093] [STDOUT] stdout: [        ] Syncing files to device swarming’s iPhone... (completed in 55ms)
 [2024-01-26 05:50:17.295126] [STDOUT] stdout: [        ] Synced 0.0MB.
 [2024-01-26 05:50:17.299998] [STDOUT] stdout: [   +4 ms] Reassembling application
 [2024-01-26 05:50:17.302670] [STDOUT] stderr: [   +2 ms] Reassembling main.dart$main-7718724522450007 failed: [Sentinel kind: Collected, valueAsString: <collected>] from ext.flutter.reassemble()
 [2024-01-26 05:50:17.302699] [STDOUT] stderr:            #0      new _OutstandingRequest (package:vm_service/src/vm_service.dart:265:34)
 [2024-01-26 05:50:17.302722] [STDOUT] stderr:            #1      VmService._call.<anonymous closure> (package:vm_service/src/vm_service.dart:1771:25)
 [2024-01-26 05:50:17.302741] [STDOUT] stderr:            #2      VmService._call (package:vm_service/src/vm_service.dart:1783:8)
 [2024-01-26 05:50:17.302759] [STDOUT] stderr:            #3      VmService.callServiceExtension (package:vm_service/src/vm_service.dart:1733:14)
 [2024-01-26 05:50:17.302777] [STDOUT] stderr:            #4      FlutterVmService._checkedCallServiceExtension (package:flutter_tools/src/vmservice.dart:868:28)
 [2024-01-26 05:50:17.302796] [STDOUT] stderr:            #5      FlutterVmService.invokeFlutterExtensionRpcRaw (package:flutter_tools/src/vmservice.dart:887:49)
 [2024-01-26 05:50:17.302814] [STDOUT] stderr:            #6      FlutterVmService.flutterReassemble (package:flutter_tools/src/vmservice.dart:728:12)
 [2024-01-26 05:50:17.302833] [STDOUT] stderr:            #7      _defaultReassembleHelper (package:flutter_tools/src/run_hot.dart:1450:63)
 [2024-01-26 05:50:17.302851] [STDOUT] stderr:            <asynchronous suspension>
 [2024-01-26 05:50:17.302869] [STDOUT] stderr:            #8      HotRunner._reloadSources (package:flutter_tools/src/run_hot.dart:1060:47)
 [2024-01-26 05:50:17.302886] [STDOUT] stderr:            <asynchronous suspension>
 [2024-01-26 05:50:17.302904] [STDOUT] stderr:            #9      HotRunner._hotReloadHelper (package:flutter_tools/src/run_hot.dart:928:16)
 [2024-01-26 05:50:17.302921] [STDOUT] stderr:            <asynchronous suspension>
 [2024-01-26 05:50:17.302938] [STDOUT] stderr:            #10     HotRunner.restart (package:flutter_tools/src/run_hot.dart:802:36)
 [2024-01-26 05:50:17.302955] [STDOUT] stderr:            <asynchronous suspension>
 [2024-01-26 05:50:17.302973] [STDOUT] stderr:            #11     HotRunner.attach (package:flutter_tools/src/run_hot.dart:345:7)
 [2024-01-26 05:50:17.302990] [STDOUT] stderr:            <asynchronous suspension>
 [2024-01-26 05:50:17.303007] [STDOUT] stderr:            #12     RunCommand.runCommand (package:flutter_tools/src/commands/run.dart:806:27)
 [2024-01-26 05:50:17.303025] [STDOUT] stderr:            <asynchronous suspension>
 [2024-01-26 05:50:17.303043] [STDOUT] stderr:            #13     FlutterCommand.run.<anonymous closure> (package:flutter_tools/src/runner/flutter_command.dart:1398:27)
 [2024-01-26 05:50:17.303061] [STDOUT] stderr:            <asynchronous suspension>
 [2024-01-26 05:50:17.303078] [STDOUT] stderr:            #14     AppContext.run.<anonymous closure> (package:flutter_tools/src/base/context.dart:153:19)
 [2024-01-26 05:50:17.303097] [STDOUT] stderr:            <asynchronous suspension>
 [2024-01-26 05:50:17.303115] [STDOUT] stderr:            #15     CommandRunner.runCommand (package:args/command_runner.dart:212:13)
 [2024-01-26 05:50:17.303132] [STDOUT] stderr:            <asynchronous suspension>
 [2024-01-26 05:50:17.303151] [STDOUT] stderr:            #16     FlutterCommandRunner.runCommand.<anonymous closure> (package:flutter_tools/src/runner/flutter_command_runner.dart:355:9)
 [2024-01-26 05:50:17.303169] [STDOUT] stderr:            <asynchronous suspension>
 [2024-01-26 05:50:17.303186] [STDOUT] stderr:            #17     AppContext.run.<anonymous closure> (package:flutter_tools/src/base/context.dart:153:19)
 [2024-01-26 05:50:17.303204] [STDOUT] stderr:            <asynchronous suspension>
 [2024-01-26 05:50:17.303222] [STDOUT] stderr:            #18     FlutterCommandRunner.runCommand (package:flutter_tools/src/runner/flutter_command_runner.dart:295:5)
 [2024-01-26 05:50:17.303240] [STDOUT] stderr:            <asynchronous suspension>
 [2024-01-26 05:50:17.303257] [STDOUT] stderr:            #19     run.<anonymous closure>.<anonymous closure> (package:flutter_tools/runner.dart:119:9)
 [2024-01-26 05:50:17.303274] [STDOUT] stderr:            <asynchronous suspension>
 [2024-01-26 05:50:17.303292] [STDOUT] stderr:            #20     AppContext.run.<anonymous closure> (package:flutter_tools/src/base/context.dart:153:19)
 [2024-01-26 05:50:17.303310] [STDOUT] stderr:            <asynchronous suspension>
 [2024-01-26 05:50:17.303327] [STDOUT] stderr:            #21     main (package:flutter_tools/executable.dart:90:3)
 [2024-01-26 05:50:17.303344] [STDOUT] stderr:            <asynchronous suspension>
 [2024-01-26 05:50:17.303361] [STDOUT] stderr: 
 [2024-01-26 05:50:17.303389] [STDOUT] stdout: [        ] Hot reload performed in 82ms.
 [2024-01-26 05:50:17.303408] [STDOUT] stdout: [        ] Performing hot reload... (completed in 90ms)
 [2024-01-26 05:59:11.109378] [STDOUT] stdout: [+533817 ms] mDNS query failed. Checking for an interface with a ipv4 link local address.
 [2024-01-26 05:59:11.112165] [STDOUT] stdout: [   +3 ms] Found interface "en8":
 [2024-01-26 05:59:11.112512] [STDOUT] stdout: [        ] 	Bound address: "169.254.225.205" link local
 [2024-01-26 05:59:11.112573] [STDOUT] stdout: [        ] Found interface "en0":
 [2024-01-26 05:59:11.112633] [STDOUT] stdout: [        ] 	Bound address: "100.91.177.53" 
 [2024-01-26 05:59:11.112829] [STDOUT] stdout: [        ] An interface with an ipv4 link local address was found.
@vashworth
Copy link
Contributor Author

Mac_x64_ios hot_mode_dev_cycle_ios__benchmark does not appear to be having this problem.

@vashworth vashworth added tool Affects the "flutter" command-line tool. See also t: labels. c: flake Tests that sometimes, but not always, incorrectly pass fyi-ios For the attention of iOS platform team team-tool Owned by Flutter Tool team labels Jan 26, 2024
@vashworth
Copy link
Contributor Author

vashworth commented Jan 26, 2024 •
edited

fyi @godofredoc This is one of the tests you added to run on arm64 (it was previously only running on x64): #141910.

@LouiseHsu LouiseHsu added the triaged-ios Triaged by iOS platform team label Jan 29, 2024
@flutter-triage-bot flutter-triage-bot bot removed fyi-ios For the attention of iOS platform team triaged-ios Triaged by iOS platform team labels Jan 29, 2024
@eliasyishak eliasyishak added P2 Important issues not at the top of the work list triaged-tool Triaged by Flutter Tool team labels Jan 30, 2024
@vashworth
Copy link
Contributor Author

@bkonyi I was told you might have some insight into this or would know who might have insight into this

@bkonyi
Copy link
Contributor

bkonyi commented Feb 1, 2024

I'm not 100% sure without digging into the code, but it looks like we're trying to invoke a service extension on an isolate that no longer exists (that would result in a Collected Sentinel response).

@vashworth vashworth added the dependency: dart Dart team may need to help us label Feb 5, 2024
@a-siva
Copy link
Contributor

a-siva commented Feb 8, 2024

@vashworth looks like this could potentially be an issue with the test, can you or somebody from the Flutter team investigate and confirm that.

@a-siva a-siva added the dependency:dart-triaged Triaged by Dart team label Feb 8, 2024
@vashworth
Copy link
Contributor Author

@vashworth looks like this could potentially be an issue with the test, can you or somebody from the Flutter team investigate and confirm that.

I don't believe this is an issue with the test. The same test runs successfully on other platforms such as linux, windows, android. It also runs successfully on iOS devices on x86 mac bots. It only seems to fail on iOS device on arm64 bots.

@a-siva
Copy link
Contributor

a-siva commented Feb 20, 2024

//cc @bkonyi we probably need to investigate further

@a-siva
Copy link
Contributor

a-siva commented Mar 6, 2024

@vashworth is it possible to get a local reproduction of this on an iOS arm64 device so we can debug the issue.

@vashworth
Copy link
Contributor Author

Unfortunately it does not happen consistently - seems to happen 1-2 times every 50 builds. If you want to run the test locally, you can run

cd flutter/dev/devicelab 
dart bin/test_runner.dart test -t hot_mode_dev_cycle_ios__benchmark -d [physical-ios-device-id]

If you're wanting specific logs or information, perhaps we can get it uploaded through CI - let me know

@bkonyi
Copy link
Contributor

bkonyi commented Mar 12, 2024

So I'm not sure I'll be able to reproduce this since I'm still using an Intel MacBook. However, there's a couple of things in the logs that are concerning.

First of all, there's this output on stderr:

 [2024-01-26 05:50:07.164176] [STDOUT] stderr: ERROR - 2024-01-26 05:50:07.163999
 [2024-01-26 05:50:07.164218] [STDOUT] stderr: PUT /cvAGasOHVbU=/
 [2024-01-26 05:50:07.164229] [STDOUT] stderr: Error thrown by handler.
 [2024-01-26 05:50:07.164237] [STDOUT] stderr: Connection reset by peer
 [2024-01-26 05:50:07.167345] [STDOUT] stderr: package:shelf/shelf_io.dart 138:16  handleRequest

This happens between Updating files and DevFS: Sync finished. I'm not sure where this shelf handler error is coming from, but I'm guessing it's related to the failure.

Afterwards, we accept the compilation and attempt to create the new isolate, where we see the following errors from the engine:

 [2024-01-26 05:50:07.200064] [STDOUT] stdout: [  +30 ms] [ERROR:flutter/shell/common/shell.cc(117)] Dart Error: Can't load Kernel binary: Invalid kernel binary: Indicated size is invalid.
 [2024-01-26 05:50:07.200129] [STDOUT] stdout: [        ] [ERROR:flutter/runtime/dart_isolate.cc(144)] Could not prepare isolate.
 [2024-01-26 05:50:07.202566] [STDOUT] stdout: [   +2 ms] Performing hot restart... (completed in 440ms)
 [2024-01-26 05:50:07.202612] [STDOUT] stdout: [        ] Restarted application in 507ms.
 [2024-01-26 05:50:07.223161] [STDOUT] stdout: [  +20 ms] [ERROR:flutter/runtime/runtime_controller.cc(462)] Could not create root isolate.

It looks like the kernel that was sent to the device is invalid, since "Indicated size is invalid" is reported when the kernel loader finds a program file start index that's less than 0. This results in us being unable to start the new isolate with the updated kernel. We then see the stack trace from package:vm_service since the isolate we were communicating with has been destroyed as part of the hot restart, which will cause a collected sentinel to be returned for any request made against the old isolate's ID.

I think we need to identify where the shelf error is being output to figure out what's going on here. My gut tells me that something's corrupting the kernel being generated by the compilation server, but I'm not 100% sure.

@bkonyi
Copy link
Contributor

bkonyi commented Mar 12, 2024

@vashworth can you try passing --no-dds to the flutter run command for the benchmark and see if that resolves the failure? I'm not sure why DDS would be encountering a Connection reset by peer exception in this case, but it's the only in the tool that hosts a Shelf server that I can see. If that fixes the issue, we'll need to add additional logging in DDS to get a better idea of which connection is failing.

@vashworth vashworth mentioned this issue Mar 18, 2024
Merged
9 tasks
auto-submit bot pushed a commit that referenced this issue Mar 18, 2024
@vashworth
Add --no-dds to Mac_arm64_ios version of hot_mode_dev_cycle_ios__benc…
7f368f7 
…hmark (#145335)

Attempting to debug #142305.
@vashworth
Copy link
Contributor Author

@vashworth can you try passing --no-dds to the flutter run command for the benchmark and see if that resolves the failure? I'm not sure why DDS would be encountering a Connection reset by peer exception in this case, but it's the only in the tool that hosts a Shelf server that I can see. If that fixes the issue, we'll need to add additional logging in DDS to get a better idea of which connection is failing.

Sorry for the delay, I added the --no-dds flag (#145335). I'll monitor the test (https://ci.chromium.org/ui/p/flutter/builders/staging/Mac_arm64_ios%20hot_mode_dev_cycle_ios__benchmark) and see if it fixes

@bkonyi
Copy link
Contributor

bkonyi commented Mar 18, 2024

Sounds good. If that fixes the crash, we'll want to add some logging in DDS to try and figure out why we're seeing this.

@vashworth
Copy link
Contributor Author

Looks like it's still crashing, but the error is a little different

https://ci.chromium.org/ui/p/flutter/builders/staging/Mac_arm64_ios%20hot_mode_dev_cycle_ios__benchmark/1037/overview

[2024-03-22 03:09:30.251677] [STDOUT] stdout: [+9815 ms] Running in benchmark mode.
 [2024-03-22 03:09:30.251762] [STDOUT] stdout: [        ] Benchmarking hot restart
 [2024-03-22 03:09:30.257736] [STDOUT] stdout: [   +6 ms] Skipping target: gen_localizations
 [2024-03-22 03:09:30.259289] [STDOUT] stdout: [   +1 ms] Skipping target: gen_dart_plugin_registrant
 [2024-03-22 03:09:30.259454] [STDOUT] stdout: [        ] Skipping target: _composite
 [2024-03-22 03:09:30.259814] [STDOUT] stdout: [        ] complete
 [2024-03-22 03:09:30.261683] [STDOUT] stdout: [   +1 ms] Performing hot restart...
 [2024-03-22 03:09:30.288549] [STDOUT] stdout: [  +26 ms] Scanned through 729 files in 24ms
 [2024-03-22 03:09:30.288735] [STDOUT] stdout: [        ] Syncing files to device swarming’s iPhone...
 [2024-03-22 03:09:30.292401] [STDOUT] stdout: [   +3 ms] <- reset
 [2024-03-22 03:09:30.292428] [STDOUT] stdout: [        ] Compiling dart to kernel with 0 updated files
 [2024-03-22 03:09:30.292564] [STDOUT] stdout: [        ] Processing bundle.
 [2024-03-22 03:09:30.292803] [STDOUT] stdout: [        ] <- recompile package:flutter_gallery/main.dart f277623b-5f53-4ffa-99d6-47cfb801cefa
 [2024-03-22 03:09:30.292818] [STDOUT] stdout: [        ] <- f277623b-5f53-4ffa-99d6-47cfb801cefa
 [2024-03-22 03:09:30.295306] [STDOUT] stdout: [   +2 ms] Bundle processing done.
 [2024-03-22 03:09:30.324914] [STDOUT] stdout: [  +29 ms] Updating files.
 [2024-03-22 03:09:30.667895] [STDOUT] stdout: [ +343 ms] Error writing "main.dart.dill" to DevFS: SocketException: Write failed (OS Error: Broken pipe, errno = 32), address = 127.0.0.1, port = 51551
 [2024-03-22 03:09:30.667914] [STDOUT] stdout: [        ] trying again in a few - 9 more attempts left
 [2024-03-22 03:09:31.550653] [STDOUT] stdout: [ +882 ms] DevFS: Sync finished
 [2024-03-22 03:09:31.550671] [STDOUT] stdout: [        ] Syncing files to device swarming’s iPhone... (completed in 1,261ms)
 [2024-03-22 03:09:31.550773] [STDOUT] stdout: [        ] Synced 40.9MB.
 [2024-03-22 03:09:31.550892] [STDOUT] stdout: [        ] <- accept
 [2024-03-22 03:09:31.551951] [STDOUT] stdout: [   +1 ms] error: HttpException: Connection closed while receiving data, uri = http://127.0.0.1:51545/vMxhdoVfvrI=/
 [2024-03-22 03:09:31.576207] [STDOUT] stdout: [  +24 ms] [ERROR:flutter/shell/common/shell.cc(117)] Dart Error: Can't load Kernel binary: Invalid kernel binary: Indicated size is invalid.
 [2024-03-22 03:09:31.577914] [STDOUT] stdout: [   +1 ms] Performing hot restart... (completed in 1,316ms)
 [2024-03-22 03:09:31.577990] [STDOUT] stdout: [        ] Restarted application in 1,324ms.
 [2024-03-22 03:09:31.578357] [STDOUT] stdout: [        ] [ERROR:flutter/runtime/dart_isolate.cc(146)] Could not prepare isolate.
 [2024-03-22 03:09:31.578365] [STDOUT] stdout: [        ] [ERROR:flutter/runtime/runtime_controller.cc(487)] Could not create root isolate.
 [2024-03-22 03:09:41.582706] [STDOUT] stdout: [+10003 ms] Benchmarking hot reload
 [2024-03-22 03:09:41.584988] [STDOUT] stdout: [   +2 ms] Skipping target: gen_localizations
 [2024-03-22 03:09:41.586311] [STDOUT] stdout: [   +1 ms] Skipping target: gen_dart_plugin_registrant
 [2024-03-22 03:09:41.586501] [STDOUT] stdout: [        ] Skipping target: _composite
 [2024-03-22 03:09:41.586708] [STDOUT] stdout: [        ] complete
 [2024-03-22 03:09:41.588299] [STDOUT] stdout: [   +1 ms] Performing hot reload...
 [2024-03-22 03:09:41.618005] [STDOUT] stdout: [  +29 ms] Scanned through 729 files in 21ms
 [2024-03-22 03:09:41.618301] [STDOUT] stdout: [        ] Syncing files to device swarming’s iPhone...
 [2024-03-22 03:09:41.622259] [STDOUT] stdout: [   +4 ms] Compiling dart to kernel with 0 updated files
 [2024-03-22 03:09:41.622393] [STDOUT] stdout: [        ] Processing bundle.
 [2024-03-22 03:09:41.622768] [STDOUT] stdout: [        ] <- recompile package:flutter_gallery/main.dart ffae8438-ab1a-486e-b3f6-2327551534ea
 [2024-03-22 03:09:41.622787] [STDOUT] stdout: [        ] <- ffae8438-ab1a-486e-b3f6-2327551534ea
 [2024-03-22 03:09:41.625152] [STDOUT] stdout: [   +2 ms] Bundle processing done.
 [2024-03-22 03:09:41.633529] [STDOUT] stdout: [   +8 ms] Updating files.
 [2024-03-22 03:09:41.664667] [STDOUT] stdout: [  +31 ms] DevFS: Sync finished
 [2024-03-22 03:09:41.664871] [STDOUT] stdout: [        ] Syncing files to device swarming’s iPhone... (completed in 46ms)
 [2024-03-22 03:09:41.664890] [STDOUT] stdout: [        ] Synced 0.0MB.
 [2024-03-22 03:09:41.669500] [STDOUT] stdout: [   +4 ms] Reassembling application
 [2024-03-22 03:09:41.671454] [STDOUT] stderr: [   +1 ms] Reassembling main.dart$main-8751169646345199 failed: [Sentinel kind: Collected, valueAsString: <collected>] from ext.flutter.reassemble()
 [2024-03-22 03:09:41.671472] [STDOUT] stderr:            #0      new _OutstandingRequest (package:vm_service/src/vm_service.dart:265:34)
 [2024-03-22 03:09:41.671482] [STDOUT] stderr:            #1      VmService._call.<anonymous closure> (package:vm_service/src/vm_service.dart:1772:25)
 [2024-03-22 03:09:41.671492] [STDOUT] stderr:            #2      VmService._call (package:vm_service/src/vm_service.dart:1784:8)
 [2024-03-22 03:09:41.671502] [STDOUT] stderr:            #3      VmService.callServiceExtension (package:vm_service/src/vm_service.dart:1733:14)
 [2024-03-22 03:09:41.671512] [STDOUT] stderr:            #4      FlutterVmService._checkedCallServiceExtension (package:flutter_tools/src/vmservice.dart:868:28)
 [2024-03-22 03:09:41.671522] [STDOUT] stderr:            #5      FlutterVmService.invokeFlutterExtensionRpcRaw (package:flutter_tools/src/vmservice.dart:887:49)
 [2024-03-22 03:09:41.671532] [STDOUT] stderr:            #6      FlutterVmService.flutterReassemble (package:flutter_tools/src/vmservice.dart:728:12)
 [2024-03-22 03:09:41.671542] [STDOUT] stderr:            #7      _defaultReassembleHelper (package:flutter_tools/src/run_hot.dart:1435:63)
 [2024-03-22 03:09:41.671551] [STDOUT] stderr:            <asynchronous suspension>
 [2024-03-22 03:09:41.671578] [STDOUT] stderr:            #8      HotRunner._reloadSources (package:flutter_tools/src/run_hot.dart:1045:47)
 [2024-03-22 03:09:41.671588] [STDOUT] stderr:            <asynchronous suspension>
 [2024-03-22 03:09:41.671598] [STDOUT] stderr:            #9      HotRunner._hotReloadHelper (package:flutter_tools/src/run_hot.dart:913:16)
 [2024-03-22 03:09:41.671607] [STDOUT] stderr:            <asynchronous suspension>
 [2024-03-22 03:09:41.671616] [STDOUT] stderr:            #10     HotRunner.restart (package:flutter_tools/src/run_hot.dart:787:36)
 [2024-03-22 03:09:41.671625] [STDOUT] stderr:            <asynchronous suspension>
 [2024-03-22 03:09:41.671635] [STDOUT] stderr:            #11     HotRunner.attach (package:flutter_tools/src/run_hot.dart:338:7)
 [2024-03-22 03:09:41.671644] [STDOUT] stderr:            <asynchronous suspension>
 [2024-03-22 03:09:41.671654] [STDOUT] stderr:            #12     RunCommand.runCommand (package:flutter_tools/src/commands/run.dart:833:27)
 [2024-03-22 03:09:41.671664] [STDOUT] stderr:            <asynchronous suspension>
 [2024-03-22 03:09:41.671673] [STDOUT] stderr:            #13     FlutterCommand.run.<anonymous closure> (package:flutter_tools/src/runner/flutter_command.dart:1394:27)
 [2024-03-22 03:09:41.671682] [STDOUT] stderr:            <asynchronous suspension>
 [2024-03-22 03:09:41.671707] [STDOUT] stderr:            #14     AppContext.run.<anonymous closure> (package:flutter_tools/src/base/context.dart:153:19)
 [2024-03-22 03:09:41.671719] [STDOUT] stderr:            <asynchronous suspension>
 [2024-03-22 03:09:41.671729] [STDOUT] stderr:            #15     CommandRunner.runCommand (package:args/command_runner.dart:212:13)
 [2024-03-22 03:09:41.671738] [STDOUT] stderr:            <asynchronous suspension>
 [2024-03-22 03:09:41.671748] [STDOUT] stderr:            #16     FlutterCommandRunner.runCommand.<anonymous closure> (package:flutter_tools/src/runner/flutter_command_runner.dart:360:9)
 [2024-03-22 03:09:41.671758] [STDOUT] stderr:            <asynchronous suspension>
 [2024-03-22 03:09:41.671768] [STDOUT] stderr:            #17     AppContext.run.<anonymous closure> (package:flutter_tools/src/base/context.dart:153:19)
 [2024-03-22 03:09:41.671778] [STDOUT] stderr:            <asynchronous suspension>
 [2024-03-22 03:09:41.671787] [STDOUT] stderr:            #18     FlutterCommandRunner.runCommand (package:flutter_tools/src/runner/flutter_command_runner.dart:300:5)
 [2024-03-22 03:09:41.671797] [STDOUT] stderr:            <asynchronous suspension>
 [2024-03-22 03:09:41.671806] [STDOUT] stderr:            #19     run.<anonymous closure>.<anonymous closure> (package:flutter_tools/runner.dart:119:9)
 [2024-03-22 03:09:41.671815] [STDOUT] stderr:            <asynchronous suspension>
 [2024-03-22 03:09:41.671824] [STDOUT] stderr:            #20     AppContext.run.<anonymous closure> (package:flutter_tools/src/base/context.dart:153:19)
 [2024-03-22 03:09:41.671834] [STDOUT] stderr:            <asynchronous suspension>
 [2024-03-22 03:09:41.671843] [STDOUT] stderr:            #21     main (package:flutter_tools/executable.dart:94:3)
 [2024-03-22 03:09:41.671852] [STDOUT] stderr:            <asynchronous suspension>

@bkonyi
Copy link
Contributor

bkonyi commented Mar 22, 2024

Thanks for the update, it's good to know this isn't being caused by weirdness in DDS.

Digging through DevFS code in flutter_tools I found an issue referenced that might be related: dart-lang/sdk#43525. It appears we've had issues with PUT requests on iOS before, but it was also impossible to reproduce. I think there's a chance this is the cause of the issue we're encountering, or at the very least related. If we're uploading an invalid dill file, the engine will fail to load it correctly and won't be able to spawn an isolate with the new code.

Maybe @brianquinlan will have some idea as to how we can try and reproduce this?

@a-siva
Copy link
Contributor

a-siva commented Mar 25, 2024

//cc @brianquinlan

@brianquinlan
Copy link
Contributor

I don't think that there is enough information here to diagnose this. @vashworth is it possible to add additional diagnostics to flutter_tools ?

@brianquinlan
Copy link
Contributor

Some of the error logs implicate this code:

This snippet, in particular, seems a bit suspicious to me:

          final HttpClientResponse response = await request.close().timeout(
            const Duration(seconds: 60));
          response.listen((_) {},
            onError: (dynamic error) {
              _logger.printTrace('error: $error');
            },
            cancelOnError: true,
          );

So we are:

  1. not checking the HTTP response code
  2. silently discarding errors
  3. not waiting for the listener to complete (is the desired semantic: await response.drain().catchError((_) {})?)

In the logs on #142305 (comment), we have:

error: HttpException: Connection closed while receiving data, uri = http://127.0.0.1:51545/vMxhdoVfvrI=/

So we are print an error because we disconnected to the remote but we discard the error, which means that the retry logic is not invoked.

Maybe the response handling code should look like:

          final HttpClientResponse response = await request.close().timeout(
            const Duration(seconds: 60));
          if (response.statusCode != 200) {
            throw new Exception('Excepted 200 response from DevFS, got ${response.statusCode}');
          }
         await response.drain();

It is possible that the remote isn't doing the right thing if a disconnect happens before the entire response body is transmitted.

@a-siva
Copy link
Contributor

a-siva commented Mar 29, 2024

//cc @christopherfujino

@vashworth vashworth mentioned this issue Apr 15, 2024
Closed
@a-siva
Copy link
Contributor

a-siva commented Apr 22, 2024

Any updates on this ?

@christopherfujino christopherfujino removed the dependency: dart Dart team may need to help us label Apr 23, 2024
@christopherfujino
Copy link
Member

Any updates on this ?

Removed dependency: dart, as it looks like this is a tool bug. This is not currently assigned, however we will probably need to fix this eventually--when we do, we should try the change proposed in: #142305 (comment)

@vashworth vashworth mentioned this issue May 6, 2024
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
c: flake Tests that sometimes, but not always, incorrectly pass dependency:dart-triaged Triaged by Dart team P2 Important issues not at the top of the work list team-tool Owned by Flutter Tool team tool Affects the "flutter" command-line tool. See also t: labels. triaged-tool Triaged by Flutter Tool team
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
7 participants
@christopherfujino @a-siva @brianquinlan @vashworth @bkonyi @LouiseHsu @eliasyishak