Log all lines from ios-deploy (#127502)

Reland https://github.com/flutter/flutter/pull/127222 that was reverted in https://github.com/flutter/flutter/pull/127405.

Fixed `Mac_ios microbenchmarks_ios` test failure by not echoing logs twice.

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

@@ -348,6 +348,12 @@ class IOSDeployDebugger {
           .transform<String>(utf8.decoder)
           .transform<String>(const LineSplitter())
           .listen((String line) {
+
+        // TODO(vashworth): Revert after https://github.com/flutter/flutter/issues/121231 is resolved.
+        if (line.isNotEmpty) {
+          _logger.printTrace(line);
+        }
+
         _monitorIOSDeployFailure(line, _logger);
 
         // (lldb)    platform select remote-'ios' --sysroot
@@ -365,7 +371,6 @@ class IOSDeployDebugger {
           }
           final String prompt = line.substring(0, promptEndIndex);
           lldbRun = RegExp(RegExp.escape(prompt) + r'\s*run');
-          _logger.printTrace(line);
           return;
         }
 
@@ -384,7 +389,6 @@ class IOSDeployDebugger {
         // success
         // 2020-09-15 13:42:25.185474-0700 Runner[477:181141] flutter: The Dart VM service is listening on http://127.0.0.1:57782/
         if (lldbRun.hasMatch(line)) {
-          _logger.printTrace(line);
           _debuggerState = _IOSDeployDebuggerState.launching;
           // TODO(vashworth): Remove all debugger state comments when https://github.com/flutter/flutter/issues/126412 is resolved.
           _logger.printTrace('Debugger state set to launching.');
@@ -393,7 +397,6 @@ class IOSDeployDebugger {
         // Next line after "run" must be "success", or the attach failed.
         // Example: "error: process launch failed"
         if (_debuggerState == _IOSDeployDebuggerState.launching) {
-          _logger.printTrace(line);
           final bool attachSuccess = line == 'success';
           _debuggerState = attachSuccess ? _IOSDeployDebuggerState.attached : _IOSDeployDebuggerState.detached;
           _logger.printTrace('Debugger state set to ${attachSuccess ? 'attached' : 'detached'}.');
@@ -408,7 +411,6 @@ class IOSDeployDebugger {
         // process signal SIGSTOP
         if (line.contains(_signalStop)) {
           // The app is about to be stopped. Only show in verbose mode.
-          _logger.printTrace(line);
           return;
         }
 
@@ -421,7 +423,6 @@ class IOSDeployDebugger {
 
         if (line == _backTraceAll) {
           // The app is stopped and the backtrace for all threads will be printed.
-          _logger.printTrace(line);
           // Even though we're not "detached", just stopped, mark as detached so the backtrace
           // is only show in verbose.
           _debuggerState = _IOSDeployDebuggerState.detached;
@@ -438,7 +439,6 @@ class IOSDeployDebugger {
 
         if (line.contains('PROCESS_STOPPED') || _lldbProcessStopped.hasMatch(line)) {
           // The app has been stopped. Dump the backtrace, and detach.
-          _logger.printTrace(line);
           _iosDeployProcess?.stdin.writeln(_backTraceAll);
           if (_processResumeCompleter == null) {
             detach();
@@ -449,20 +449,17 @@ class IOSDeployDebugger {
         if (line.contains('PROCESS_EXITED') || _lldbProcessExit.hasMatch(line)) {
           // The app exited or crashed, so exit. Continue passing debugging
           // messages to the log reader until it exits to capture crash dumps.
-          _logger.printTrace(line);
           exit();
           return;
         }
         if (_lldbProcessDetached.hasMatch(line)) {
           // The debugger has detached from the app, and there will be no more debugging messages.
           // Kill the ios-deploy process.
-          _logger.printTrace(line);
           exit();
           return;
         }
 
         if (_lldbProcessResuming.hasMatch(line)) {
-          _logger.printTrace(line);
           // we marked this detached when we received [_backTraceAll]
           _debuggerState = _IOSDeployDebuggerState.attached;
           _logger.printTrace('Debugger state set to attached.');
@@ -470,7 +467,6 @@ class IOSDeployDebugger {
         }
 
         if (_debuggerState != _IOSDeployDebuggerState.attached) {
-          _logger.printTrace(line);
           return;
         }
         if (lastLineFromDebugger != null && lastLineFromDebugger!.isNotEmpty && line.isEmpty) {
@@ -488,7 +484,7 @@ class IOSDeployDebugger {
           .transform<String>(const LineSplitter())
           .listen((String line) {
         _monitorIOSDeployFailure(line, _logger);
-        _logger.printTrace(line);
+        _logger.printTrace('error: $line');
       });
       unawaited(_iosDeployProcess!.exitCode.then((int status) async {
         _logger.printTrace('ios-deploy exited with code $exitCode');

packages/flutter_tools/lib/src/resident_runner.dart

@@ -36,6 +36,7 @@ import 'devfs.dart';
 import 'device.dart';
 import 'features.dart';
 import 'globals.dart' as globals;
+import 'ios/devices.dart';
 import 'project.dart';
 import 'resident_devtools_handler.dart';
 import 'run_cold.dart';
@@ -228,8 +229,9 @@ class FlutterDevice {
   FlutterVmService? vmService;
   DevFS? devFS;
   ApplicationPackage? package;
+  @visibleForTesting
   // ignore: cancel_subscriptions
-  StreamSubscription<String>? _loggingSubscription;
+  StreamSubscription<String>? loggingSubscription;
   bool? _isListeningForVmServiceUri;
 
   /// Whether the stream [vmServiceUris] is still open.
@@ -392,23 +394,26 @@ class FlutterDevice {
   }
 
   Future<void> startEchoingDeviceLog() async {
-    if (_loggingSubscription != null) {
+    if (loggingSubscription != null) {
       return;
     }
-    final Stream<String> logStream = (await device!.getLogReader(app: package)).logLines;
+    final DeviceLogReader logReader = await device!.getLogReader(app: package);
-    _loggingSubscription = logStream.listen((String line) {
+    final Stream<String> logStream = logReader.logLines;
-      if (!line.contains(globals.kVMServiceMessageRegExp)) {
+    // TODO(vashworth): Remove check for IOSDeviceLogReader after
+    // https://github.com/flutter/flutter/issues/121231 is resolved.
+    loggingSubscription = logStream.listen((String line) {
+      if (logReader is! IOSDeviceLogReader && !line.contains(globals.kVMServiceMessageRegExp)) {
         globals.printStatus(line, wrap: false);
       }
     });
   }
 
   Future<void> stopEchoingDeviceLog() async {
-    if (_loggingSubscription == null) {
+    if (loggingSubscription == null) {
       return;
     }
-    await _loggingSubscription!.cancel();
+    await loggingSubscription!.cancel();
-    _loggingSubscription = null;
+    loggingSubscription = null;
   }
 
   Future<void> initLogReader() async {

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

@@ -94,6 +94,26 @@ void main () {
         logger = BufferLogger.test();
       });
 
+      testWithoutContext('print all lines', () async {
+        final StreamController<List<int>> stdin = StreamController<List<int>>();
+        final FakeProcessManager processManager = FakeProcessManager.list(<FakeCommand>[
+          FakeCommand(
+            command: const <String>['ios-deploy'],
+            stdout: "(mylldb)    platform select remote-'ios' --sysroot\r\n(mylldb)     run\r\nsuccess\r\nrandom string\r\n",
+            stdin: IOSink(stdin.sink),
+          ),
+        ]);
+        final IOSDeployDebugger iosDeployDebugger = IOSDeployDebugger.test(
+          processManager: processManager,
+          logger: logger,
+        );
+        expect(await iosDeployDebugger.launchAndAttach(), isTrue);
+        expect(logger.traceText, contains("(mylldb)    platform select remote-'ios' --sysroot"));
+        expect(logger.traceText, contains('(mylldb)     run'));
+        expect(logger.traceText, contains('success'));
+        expect(logger.traceText, contains('random string'));
+      });
+
       testWithoutContext('custom lldb prompt', () async {
         final StreamController<List<int>> stdin = StreamController<List<int>>();
         final FakeProcessManager processManager = FakeProcessManager.list(<FakeCommand>[

packages/flutter_tools/test/general.shard/resident_runner_test.dart

@@ -20,6 +20,7 @@ import 'package:flutter_tools/src/base/platform.dart';
 import 'package:flutter_tools/src/build_info.dart';
 import 'package:flutter_tools/src/build_system/targets/scene_importer.dart';
 import 'package:flutter_tools/src/build_system/targets/shader_compiler.dart';
+import 'package:flutter_tools/src/cache.dart';
 import 'package:flutter_tools/src/compile.dart';
 import 'package:flutter_tools/src/convert.dart';
 import 'package:flutter_tools/src/devfs.dart';
@@ -27,6 +28,8 @@ import 'package:flutter_tools/src/device.dart';
 import 'package:flutter_tools/src/device_port_forwarder.dart';
 import 'package:flutter_tools/src/features.dart';
 import 'package:flutter_tools/src/globals.dart' as globals;
+import 'package:flutter_tools/src/ios/devices.dart';
+import 'package:flutter_tools/src/ios/mac.dart';
 import 'package:flutter_tools/src/project.dart';
 import 'package:flutter_tools/src/reporting/reporting.dart';
 import 'package:flutter_tools/src/resident_devtools_handler.dart';
@@ -41,6 +44,7 @@ import 'package:vm_service/vm_service.dart' as vm_service;
 
 import '../src/common.dart';
 import '../src/context.dart';
+import '../src/fake_devices.dart';
 import '../src/fake_vm_services.dart';
 import '../src/fakes.dart';
 import '../src/testbed.dart';
@@ -2438,6 +2442,70 @@ flutter:
     expect(flutterDevice.devFS!.hasSetAssetDirectory, true);
     expect(fakeVmServiceHost!.hasRemainingExpectations, false);
   }));
+
+  group('startEchoingDeviceLog', () {
+    late FakeProcessManager processManager;
+    late Artifacts artifacts;
+    late Cache fakeCache;
+    late BufferLogger logger;
+
+    setUp(() {
+      processManager = FakeProcessManager.empty();
+      fakeCache = Cache.test(processManager: FakeProcessManager.any());
+      artifacts = Artifacts.test();
+      logger = BufferLogger.test();
+    });
+
+    testUsingContext('IOSDeviceLogReader does not print logs', () async {
+      final IOSDeviceLogReader logReader = IOSDeviceLogReader.test(
+        iMobileDevice: IMobileDevice(
+          artifacts: artifacts,
+          processManager: processManager,
+          cache: fakeCache,
+          logger: logger,
+        ),
+        useSyslog: false,
+      );
+      device = FakeDevice(deviceLogReader: logReader);
+      final TestFlutterDevice flutterDevice = TestFlutterDevice(
+        device,
+      );
+
+      await flutterDevice.startEchoingDeviceLog();
+      final Future<List<String>> linesFromStream = logReader.logLines.toList();
+      logReader.linesController.add('event');
+      await logReader.linesController.close();
+      final List<String> lines = await linesFromStream;
+
+      expect(lines, contains('event'));
+      expect(logger.statusText, isEmpty);
+
+      await flutterDevice.stopEchoingDeviceLog();
+    }, overrides: <Type, Generator>{
+      Logger: () => logger,
+    });
+
+    testUsingContext('Non-IOSDeviceLogReader does print logs', () async {
+      final FakeDeviceLogReader logReader = FakeDeviceLogReader();
+      device = FakeDevice(deviceLogReader: logReader);
+      final TestFlutterDevice flutterDevice = TestFlutterDevice(
+        device,
+      );
+
+      await flutterDevice.startEchoingDeviceLog();
+      final Future<List<String>> linesFromStream = logReader.logLines.toList();
+      logReader.addLine('event');
+      await logReader.dispose();
+      final List<String> lines = await linesFromStream;
+
+      expect(lines, contains('event'));
+      expect(logger.statusText, contains('event'));
+
+      await flutterDevice.stopEchoingDeviceLog();
+    }, overrides: <Type, Generator>{
+      Logger: () => logger,
+    });
+  });
 }
 
 // This implements [dds.DartDevelopmentService], not the [DartDevelopmentService]
@@ -2676,13 +2744,16 @@ class FakeDevice extends Fake implements Device {
     this.supportsHotRestart = true,
     this.supportsScreenshot = true,
     this.supportsFlutterExit = true,
+    DeviceLogReader? deviceLogReader,
   }) : _isLocalEmulator = isLocalEmulator,
        _targetPlatform = targetPlatform,
-       _sdkNameAndVersion = sdkNameAndVersion;
+       _sdkNameAndVersion = sdkNameAndVersion,
+       _deviceLogReader = deviceLogReader;
 
   final bool _isLocalEmulator;
   final TargetPlatform _targetPlatform;
   final String _sdkNameAndVersion;
+  final DeviceLogReader? _deviceLogReader;
 
   bool disposed = false;
   bool appStopped = false;
@@ -2740,7 +2811,12 @@ class FakeDevice extends Fake implements Device {
   FutureOr<DeviceLogReader> getLogReader({
     ApplicationPackage? app,
     bool includePastLogs = false,
-  }) => NoOpDeviceLogReader(name);
+  }) {
+    if (_deviceLogReader != null) {
+      return _deviceLogReader!;
+    }
+    return NoOpDeviceLogReader(name);
+  }
 
   @override
   DevicePortForwarder portForwarder = const NoOpDevicePortForwarder();