Skip to content

Commit

Permalink
Log all lines from ios-deploy (#127502)
Browse files Browse the repository at this point in the history
Reland #127222 that was reverted in #127405.

Fixed `Mac_ios microbenchmarks_ios` test failure by not echoing logs twice.
  • Loading branch information
vashworth committed May 24, 2023
1 parent 555326b commit a19b343
Show file tree
Hide file tree
Showing 4 changed files with 118 additions and 21 deletions.
18 changes: 7 additions & 11 deletions packages/flutter_tools/lib/src/ios/ios_deploy.dart
Expand Up @@ -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
Expand All @@ -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;
}

Expand All @@ -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.');
Expand All @@ -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'}.');
Expand All @@ -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;
}

Expand All @@ -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;
Expand All @@ -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();
Expand All @@ -449,28 +449,24 @@ 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.');
return;
}

if (_debuggerState != _IOSDeployDebuggerState.attached) {
_logger.printTrace(line);
return;
}
if (lastLineFromDebugger != null && lastLineFromDebugger!.isNotEmpty && line.isEmpty) {
Expand All @@ -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');
Expand Down
21 changes: 13 additions & 8 deletions packages/flutter_tools/lib/src/resident_runner.dart
Expand Up @@ -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';
Expand Down Expand Up @@ -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.
Expand Down Expand Up @@ -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;
_loggingSubscription = logStream.listen((String line) {
if (!line.contains(globals.kVMServiceMessageRegExp)) {
final DeviceLogReader logReader = await device!.getLogReader(app: package);
final Stream<String> logStream = logReader.logLines;
// 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();
_loggingSubscription = null;
await loggingSubscription!.cancel();
loggingSubscription = null;
}

Future<void> initLogReader() async {
Expand Down
20 changes: 20 additions & 0 deletions packages/flutter_tools/test/general.shard/ios/ios_deploy_test.dart
Expand Up @@ -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>[
Expand Down
Expand Up @@ -20,13 +20,16 @@ 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';
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';
Expand All @@ -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';
Expand Down Expand Up @@ -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]
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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();
Expand Down

0 comments on commit a19b343

Please sign in to comment.