Stream logging from attached debugger on iOS #66092

jmagman · 2020-09-18T07:29:19Z

Description

As of iOS 13, the host can't directly read the device logs from the host. #43915 connected to the VM observatory and read the log lines from the logging services.

On flutter run and flutter drive (not attach in this PR), instead of waiting to attach to the observatory, instead launch the app with the debugger and stay attached to stream in the logs from lldb. See #54781 (comment) for details. This should also reduce devicelab flakes.

This will give the tool access to:

The observatory port log line
Full native crash backtraces, including crashes on launch before the engine starts
dart print()
dart stderr.writeln, other I/O sinks
native logging (os_log, asserts etc)
Engine logs (may need follow up work to filter out the verbose category)

Notes

Keep the VM service connection for flutter attach. A follow up PR could attach the debugger in that scenario as well (without re-launching), and then the VM connection can be removed.
Keep the syslog connection for <iOS 13. I wasn't able to get this working on my iOS 9.3.6 test device, so don't regress it. If I can get that working, we can also remove idevicesyslog.

Related Issues

Fixes #44717
Fixes #44718
Fixes #54781

#39240 (fixes run/drive, not attach)
#58078 (fixes run/drive, not attach)

Mitigate #46705 (run/drive, not attach)
Will allow us to turn off mDNS fallback for drive on CI to solve iOS 14 issue #65207

Note to self: check if this fixes #19196

Tests

ios_deploy_tests
ios_device_logger_tests
ios_device_start_prebuilt_tests

Follow up with logging integration tests so this stops regressing.

Also, manually tested:

Detaching doesn't stop the app.
ios-deploy processes aren't leaking

Checklist

I read the [Contributor Guide] and followed the process outlined there for submitting PRs.
I signed the [CLA].
I read and followed the [Flutter Style Guide], including [Features we expect every widget to implement].
I read the [Tree Hygiene] wiki page, which explains my responsibilities.
I updated/added relevant documentation (doc comments with ///).
All existing and new tests are passing.
The analyzer (flutter analyze --flutter-repo) does not report any problems on my PR.
I am willing to follow-up on review comments in a timely manner.

Breaking Change

No, no existing tests failed, so this is not a breaking change.
Yes, this is a breaking change. If not, delete the remainder of this section.

jmagman · 2020-09-18T07:33:41Z

packages/flutter_tools/lib/src/ios/fallback_discovery.dart

The change in this file switches the order of fallbacks, which confused git. Now it first tries log scanning, and only if that fails, falls back to mDNS discovery.

packages/flutter_tools/lib/src/ios/fallback_discovery.dart

jmagman · 2020-09-18T07:37:04Z

packages/flutter_tools/lib/src/protocol_discovery.dart

This was previously waiting and buffering for duration before sending the first message. The observatory URL was discovered faster than 200 ms in my tests, so let's not wait to process it.

jonahwilliams

If this is successful should we remove the mDNS fallback entirely? Could we also remove the provisioning logic for the mDNS permissions?

jonahwilliams · 2020-09-18T17:43:45Z

packages/flutter_tools/lib/src/ios/ios_deploy.dart

+        // (lldb)     run
+        // success
+        // 2020-09-15 13:42:25.185474-0700 Runner[477:181141] flutter: Observatory listening on http://127.0.0.1:57782/
+        if (line == '(lldb)     run') {


this might deserve a const, with a doc describing where you found it.

packages/flutter_tools/lib/src/ios/ios_deploy.dart

jonahwilliams · 2020-09-18T17:45:01Z

packages/flutter_tools/lib/src/ios/ios_deploy.dart

+      _logger.printTrace('ios-deploy failed: $exception');
+      _debuggerAttached = false;
+      _debuggerOutput.addError(exception, stackTrace);
+    } on ArgumentError catch (exception, stackTrace) {


This will fail if ios-deploy is missing right? should we catch the error or let it crash here and solve the problem elsewhere? i.e. startup checks

I think we already have those checks in place with the stamp/artifact download logic, since ios-deploy is an artifact we ship ourselves idevicesyslog. Unlike the Xcode tooling where we do lots of install checks.

packages/flutter_tools/lib/src/ios/fallback_discovery.dart

packages/flutter_tools/lib/src/ios/ios_deploy.dart

zanderso · 2020-09-18T17:51:25Z

packages/flutter_tools/lib/src/ios/ios_deploy.dart

+        // (lldb)     run
+        // success
+        // 2020-09-15 13:42:25.185474-0700 Runner[477:181141] flutter: Observatory listening on http://127.0.0.1:57782/
+        if (line == '(lldb)     run') {


Is there any way to make this test and the test for 'success' more resilient to changes in output from lldb? Maybe ignore whitespace or unexpected lines between here and 'success'?

run is coming from ios-deploy, and success is coming from lldb. I will make this a regex to handle whitespace differences.

Added more comments and tests.

zanderso · 2020-09-18T17:53:48Z

packages/flutter_tools/lib/src/ios/ios_deploy.dart

+          debuggerCompleter.complete(false);
+          return;
+        }
+        if (!debuggerAttached) {


Oh, okay. The very next line after the lldb run line doesn't have to be 'success'. We'll wait until it is. Consider updating the comment above.

It does have to be "success" (lldbRunCalled logic where it's being set to false if the next line isn't "success"), unless I have a bug in here.

Maybe I should change this to fail if the next line isn't "success" so it doesn't hang forever on something unexpected instead of special-casing "error: process launch failed" (and example of a non-success next line).

Ah, okay. I misread the code. My suggestion for a cleanup would be to structure this explicitly as a state machine, with an enum setting out explicitly what the states are, and a big comment explaining what/when the transitions are.

That might also make testing this code easier. I think I see below that the error paths in here could use some coverage.

Added an enum, hopefully it's clearer now.

zanderso · 2020-09-18T17:56:58Z

packages/flutter_tools/lib/src/ios/ios_deploy.dart

+        _logger.printTrace('ios-deploy exited with code $exitCode');
+        _debuggerAttached = false;
+        unawaited(stdoutSubscription.cancel());
+        unawaited(stderrSubscription.cancel());


Does ios-deploy have anything interesting on its stderr when it exits with an error?

Some stuff:
https://github.com/ios-control/ios-deploy/blob/master/src/ios-deploy/ios-deploy.m#L1741
Though nothing that's probably actionable to the developer. It's being printTraced a few lines above this.
https://github.com/flutter/flutter/pull/66092/files/e91e25e01ffa596f7e60c861b435a9c672a9a29e#diff-8d108d6a887a4f5b74f7c7d77003e795R326

They seem to put actionable errors to stdout (see _monitorIOSDeployFailure parsing below, which existed before this PR).

Added _monitorIOSDeployFailure to the stderr processing in case they move how that's output. Will add a test.

zanderso · 2020-09-18T20:43:10Z

packages/flutter_tools/lib/src/ios/ios_deploy.dart

+          debuggerCompleter.complete(false);
+          return;
+        }
+        if (!debuggerAttached) {


Ah, okay. I misread the code. My suggestion for a cleanup would be to structure this explicitly as a state machine, with an enum setting out explicitly what the states are, and a big comment explaining what/when the transitions are.

That might also make testing this code easier. I think I see below that the error paths in here could use some coverage.

zanderso · 2020-09-18T20:44:46Z

packages/flutter_tools/test/general.shard/ios/ios_deploy_test.dart

+        final FakeProcessManager processManager = FakeProcessManager.list(<FakeCommand>[
+          const FakeCommand(
+            command: <String>['ios-deploy'],
+            stdout: '(lldb)     run\r\nsuccess\r\nLog on attach1\r\n\r\nLog on attach2\r\n\r\n\r\n\r\nPROCESS_STOPPED\r\nLog after process exit',


Test failure modes on unexpected stdout.

jonahwilliams

LGTM if LG to @zanderso

jmagman · 2020-09-18T21:49:38Z

If this is successful should we remove the mDNS fallback entirely? Could we also remove the provisioning logic for the mDNS permissions?

It's still used in the attach case, which would need to trickiness like interrupting the app and printing the observatory URL to on attach (there's probably a more elegant way to do this? I don't know how to detect from an app when a debugger attaches, only how to tell if it's launched with the debugger attached).

However it will allow us to remove the mDNS permission for flutter drive, which would solve #65207.

zanderso

lgtm

jmagman · 2020-09-18T22:26:14Z

Merging on red, hopefully this will deflake things (after a few reverts no doubt)

This reverts commit 5c85803.

#66359)" This reverts commit 53fee1b.

#66359)" (#66360) This reverts commit 53fee1b.

This reverts commit 5c85803.

This reverts commit 2be4570.

…" (#66397) This reverts commit 2be4570.

jmagman added the platform-ios iOS applications specifically label Sep 18, 2020

jmagman self-assigned this Sep 18, 2020

flutter-dashboard bot added tool Affects the "flutter" command-line tool. See also t: labels. work in progress; do not review labels Sep 18, 2020

googlebot added the cla: yes label Sep 18, 2020

jmagman commented Sep 18, 2020

View reviewed changes

packages/flutter_tools/lib/src/ios/fallback_discovery.dart Outdated Show resolved Hide resolved

jmagman commented Sep 18, 2020

View reviewed changes

jmagman force-pushed the debug-attach branch from 2128ca7 to 7d56f57 Compare September 18, 2020 07:39

xster mentioned this pull request Sep 18, 2020

flutter drive CI tests fail targeting iOS 14, stuck on local network permission popup #65207

Closed

Stream logging from attached debugger on iOS

e91e25e

jmagman force-pushed the debug-attach branch from 7d56f57 to e91e25e Compare September 18, 2020 08:16

jmagman marked this pull request as ready for review September 18, 2020 17:33

jmagman requested review from christopherfujino, jonahwilliams and zanderso September 18, 2020 17:33

jonahwilliams reviewed Sep 18, 2020

View reviewed changes

zanderso reviewed Sep 18, 2020

View reviewed changes

Review edits

81c0fee

jonahwilliams approved these changes Sep 18, 2020

View reviewed changes

zanderso approved these changes Sep 18, 2020

View reviewed changes

Remove leftover injected debuggerOutput from testing

a4e2b0c

jmagman merged commit 5c85803 into flutter:master Sep 18, 2020

jmagman deleted the debug-attach branch September 18, 2020 22:26

jmagman mentioned this pull request Sep 18, 2020

Gallery example app crashes on launch, dependent dylib '@rpath/Flutter.framework/Flutter' #57225

Closed

goderbauer pushed a commit to goderbauer/flutter that referenced this pull request Sep 18, 2020

Stream logging from attached debugger on iOS (flutter#66092)

2046964

jmagman mentioned this pull request Sep 18, 2020

Multiple iOS benchmarks are extremely flaky #66119

Closed

This was referenced Sep 21, 2020

Stop logging on iOS process exit #66293

Closed

Logs not printed on iOS devices on build #44718

Closed

"print" statements do not work with iOS 13.7 physical device #65519

Closed

dnfield added a commit that referenced this pull request Sep 22, 2020

Revert "Stream logging from attached debugger on iOS (#66092)"

23b6abe

This reverts commit 5c85803.

dnfield mentioned this pull request Sep 22, 2020

Revert "Stream logging from attached debugger on iOS" #66359

Merged

dnfield added a commit that referenced this pull request Sep 22, 2020

Revert "Stream logging from attached debugger on iOS (#66092)" (#66359)

53fee1b

This reverts commit 5c85803.

dnfield added a commit that referenced this pull request Sep 22, 2020

Revert "Revert "Stream logging from attached debugger on iOS (#66092)" (

70e78cd

#66359)" This reverts commit 53fee1b.

dnfield added a commit that referenced this pull request Sep 22, 2020

Revert "Revert "Stream logging from attached debugger on iOS (#66092)" (

4299dd7

#66359)" (#66360) This reverts commit 53fee1b.

christopherfujino added a commit to chris-forks/flutter that referenced this pull request Sep 22, 2020

Revert "Stream logging from attached debugger on iOS (flutter#66092)"

6edd3ad

This reverts commit 5c85803.

jmagman added a commit that referenced this pull request Sep 22, 2020

Revert "Stream logging from attached debugger on iOS (#66092)"

869c820

This reverts commit 5c85803.

jmagman mentioned this pull request Sep 22, 2020

Revert "Stream logging from attached debugger on iOS" #66368

Merged

jmagman added a commit that referenced this pull request Sep 22, 2020

Revert "Stream logging from attached debugger on iOS (#66092)" (#66368)

8d2e257

This reverts commit 5c85803.

christopherfujino added a commit that referenced this pull request Sep 22, 2020

Revert "Stream logging from attached debugger on iOS (#66092)" (#66367)

83dd176

This reverts commit 5c85803.

jmagman added a commit to jmagman/flutter that referenced this pull request Sep 22, 2020

Stream logging from attached debugger on iOS (flutter#66092)

61edfdb

jmagman mentioned this pull request Sep 22, 2020

Stream logging from attached debugger on iOS #66390

Merged

10 tasks

jmagman added a commit that referenced this pull request Sep 22, 2020

Stream logging from attached debugger on iOS (#66092) (#66390)

2be4570

jmagman added a commit that referenced this pull request Sep 22, 2020

Revert "Stream logging from attached debugger on iOS (#66092) (#66390)"

bb5b910

This reverts commit 2be4570.

jmagman added a commit that referenced this pull request Sep 22, 2020

Revert "Stream logging from attached debugger on iOS (#66092) (#66390)…

4881b4b

…" (#66397) This reverts commit 2be4570.

jmagman mentioned this pull request Sep 22, 2020

Stream logging from attached debugger on iOS 13+ #66399

Merged

10 tasks

jmagman mentioned this pull request Oct 6, 2020

Add publish-port flag to disable mDNS port discovery #67452

Merged

10 tasks

jmagman mentioned this pull request Oct 14, 2021

When macOS apps crash on launch, no crash logs printed, fails with "Error waiting for a debug connection: The log reader stopped unexpectedly, or never started." #91830

Open

Stream logging from attached debugger on iOS #66092

Stream logging from attached debugger on iOS #66092

Uh oh!

Conversation

jmagman commented Sep 18, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Description

Notes

Related Issues

Tests

Checklist

Breaking Change

Uh oh!

jmagman Sep 18, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jonahwilliams left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jonahwilliams left a comment

Choose a reason for hiding this comment

Uh oh!

jmagman commented Sep 18, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

zanderso left a comment

Choose a reason for hiding this comment

Uh oh!

jmagman commented Sep 18, 2020

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

jmagman commented Sep 18, 2020 •

edited

Loading

jmagman Sep 18, 2020 •

edited

Loading

jmagman commented Sep 18, 2020 •

edited

Loading