Observe logging from VM service on iOS 13 (#43915)

packages/flutter_tools/lib/src/device.dart

@@ -23,6 +23,7 @@ import 'linux/linux_device.dart';
 import 'macos/macos_device.dart';
 import 'project.dart';
 import 'tester/flutter_tester.dart';
+import 'vmservice.dart';
 import 'web/web_device.dart';
 import 'windows/windows_device.dart';
 
@@ -618,6 +619,10 @@ abstract class DeviceLogReader {
   /// A broadcast stream where each element in the string is a line of log output.
   Stream<String> get logLines;
 
+  /// Some logs can be obtained from a VM service stream.
+  /// Set this after the VM services are connected.
+  List<VMService> connectedVMServices;
+
   @override
   String toString() => name;
 
@@ -645,6 +650,9 @@ class NoOpDeviceLogReader implements DeviceLogReader {
   @override
   int appPid;
 
+  @override
+  List<VMService> connectedVMServices;
+
   @override
   Stream<String> get logLines => const Stream<String>.empty();
 

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

@@ -8,6 +8,7 @@ import 'package:meta/meta.dart';
 
 import '../application_package.dart';
 import '../artifacts.dart';
+import '../base/common.dart';
 import '../base/context.dart';
 import '../base/file_system.dart';
 import '../base/io.dart';
@@ -22,6 +23,7 @@ import '../mdns_discovery.dart';
 import '../project.dart';
 import '../protocol_discovery.dart';
 import '../reporting/reporting.dart';
+import '../vmservice.dart';
 import 'code_signing.dart';
 import 'ios_workflow.dart';
 import 'mac.dart';
@@ -141,6 +143,12 @@ class IOSDevice extends Device {
 
   final String _sdkVersion;
 
+  /// May be 0 if version cannot be parsed.
+  int get majorSdkVersion {
+    final String majorVersionString = _sdkVersion?.split('.')?.first?.trim();
+    return majorVersionString != null ? int.tryParse(majorVersionString) ?? 0 : 0;
+  }
+
   @override
   bool get supportsHotReload => true;
 
@@ -529,7 +537,7 @@ String decodeSyslog(String line) {
 class IOSDeviceLogReader extends DeviceLogReader {
   IOSDeviceLogReader(this.device, ApplicationPackage app) {
     _linesController = StreamController<String>.broadcast(
-      onListen: _start,
+      onListen: _listenToSysLog,
       onCancel: dispose,
     );
 
@@ -543,6 +551,7 @@ class IOSDeviceLogReader extends DeviceLogReader {
     // and "Flutter". The regex tries to strike a balance between not producing
     // false positives and not producing false negatives.
     _anyLineRegex = RegExp(r'\w+(\([^)]*\))?\[\d+\] <[A-Za-z]+>: ');
+    _loggingSubscriptions = <StreamSubscription<ServiceEvent>>[];
   }
 
   final IOSDevice device;
@@ -553,6 +562,7 @@ class IOSDeviceLogReader extends DeviceLogReader {
   RegExp _anyLineRegex;
 
   StreamController<String> _linesController;
+  List<StreamSubscription<ServiceEvent>> _loggingSubscriptions;
 
   @override
   Stream<String> get logLines => _linesController.stream;
@@ -560,10 +570,44 @@ class IOSDeviceLogReader extends DeviceLogReader {
   @override
   String get name => device.name;
 
-  void _start() {
+  @override
+  List<VMService> get connectedVMServices => _connectedVMServices;
+  List<VMService> _connectedVMServices;
+
+  @override
+  set connectedVMServices(List<VMService> connectedVMServices) {
+    _listenToUnifiedLoggingEvents(connectedVMServices);
+    _connectedVMServices = connectedVMServices;
+  }
+
+  static const int _minimumUniversalLoggingSdkVersion = 13;
+
+  Future<void> _listenToUnifiedLoggingEvents(List<VMService> vmServices) async {
+    if (device.majorSdkVersion < _minimumUniversalLoggingSdkVersion) {
+      return;
+    }
+    for (VMService vmService in vmServices) {
+      // The VM service will not publish logging events unless the debug stream is being listened to.
+      // onDebugEvent listens to this stream as a side effect.
+      unawaited(vmService.onDebugEvent);
+      _loggingSubscriptions.add((await vmService.onStdoutEvent).listen((ServiceEvent event) {
+        final String logMessage = event.message;
+        if (logMessage.isNotEmpty) {
+          _linesController.add(logMessage);
+        }
+      }));
+    }
+    _connectedVMServices = connectedVMServices;
+  }
+
+  void _listenToSysLog () {
+    // syslog is not written on iOS 13+.
+    if (device.majorSdkVersion >= _minimumUniversalLoggingSdkVersion) {
+      return;
+    }
     iMobileDevice.startLogger(device.id).then<void>((Process process) {
-      process.stdout.transform<String>(utf8.decoder).transform<String>(const LineSplitter()).listen(_newLineHandler());
-      process.stderr.transform<String>(utf8.decoder).transform<String>(const LineSplitter()).listen(_newLineHandler());
+      process.stdout.transform<String>(utf8.decoder).transform<String>(const LineSplitter()).listen(_newSyslogLineHandler());
+      process.stderr.transform<String>(utf8.decoder).transform<String>(const LineSplitter()).listen(_newSyslogLineHandler());
       process.exitCode.whenComplete(() {
         if (_linesController.hasListener) {
           _linesController.close();
@@ -584,7 +628,7 @@ class IOSDeviceLogReader extends DeviceLogReader {
   // any specific prefix. To properly capture those, we enter "printing" mode
   // after matching a log line from the runner. When in printing mode, we print
   // all lines until we find the start of another log message (from any app).
-  Function _newLineHandler() {
+  Function _newSyslogLineHandler() {
     bool printing = false;
 
     return (String line) {
@@ -611,6 +655,9 @@ class IOSDeviceLogReader extends DeviceLogReader {
 
   @override
   void dispose() {
+    for (StreamSubscription<ServiceEvent> loggingSubscription in _loggingSubscriptions) {
+      loggingSubscription.cancel();
+    }
     _idevicesyslogProcess?.kill();
   }
 }

packages/flutter_tools/lib/src/resident_runner.dart

@@ -163,6 +163,7 @@ class FlutterDevice {
       printTrace('Successfully connected to service protocol: ${observatoryUris[i]}');
     }
     vmServices = localVmServices;
+    device.getLogReader(app: package).connectedVMServices = vmServices;
   }
 
   Future<void> refreshViews() async {

packages/flutter_tools/lib/src/vmservice.dart

@@ -18,7 +18,7 @@ import 'base/context.dart';
 import 'base/file_system.dart';
 import 'base/io.dart' as io;
 import 'base/utils.dart';
-import 'convert.dart' show base64;
+import 'convert.dart' show base64, utf8;
 import 'globals.dart';
 import 'version.dart';
 import 'vmservice_record_replay.dart';
@@ -99,6 +99,10 @@ Future<StreamChannel<String>> _defaultOpenChannel(Uri uri, {io.CompressionOption
   return IOWebSocketChannel(socket).cast<String>();
 }
 
+/// Override `VMServiceConnector` in [context] to return a different VMService
+/// from [VMService.connect] (used by tests).
+typedef VMServiceConnector = Future<VMService> Function(Uri httpUri, { ReloadSources reloadSources, Restart restart, CompileExpression compileExpression, io.CompressionOptions compression });
+
 /// A connection to the Dart VM Service.
 // TODO(mklim): Test this, https://github.com/flutter/flutter/issues/23031
 class VMService {
@@ -306,6 +310,17 @@ class VMService {
       Restart restart,
       CompileExpression compileExpression,
       io.CompressionOptions compression = io.CompressionOptions.compressionDefault,
+    }) async {
+    final VMServiceConnector connector = context.get<VMServiceConnector>() ?? VMService._connect;
+    return connector(httpUri, reloadSources: reloadSources, restart: restart, compileExpression: compileExpression, compression: compression);
+  }
+
+  static Future<VMService> _connect(
+    Uri httpUri, {
+    ReloadSources reloadSources,
+    Restart restart,
+    CompileExpression compileExpression,
+    io.CompressionOptions compression = io.CompressionOptions.compressionDefault,
   }) async {
     final Uri wsUri = httpUri.replace(scheme: 'ws', path: fs.path.join(httpUri.path, 'ws'));
     final StreamChannel<String> channel = await _openChannel(wsUri, compression: compression);
@@ -344,6 +359,8 @@ class VMService {
   // IsolateStart, IsolateRunnable, IsolateExit, IsolateUpdate, ServiceExtensionAdded
   Future<Stream<ServiceEvent>> get onIsolateEvent => onEvent('Isolate');
   Future<Stream<ServiceEvent>> get onTimelineEvent => onEvent('Timeline');
+  Future<Stream<ServiceEvent>> get onStdoutEvent => onEvent('Stdout'); // WriteEvent
+
   // TODO(johnmccutchan): Add FlutterView events.
 
   /// Returns a stream of VM service events.
@@ -643,6 +660,8 @@ class ServiceEvent extends ServiceObject {
   Map<String, dynamic> get extensionData => _extensionData;
   List<Map<String, dynamic>> _timelineEvents;
   List<Map<String, dynamic>> get timelineEvents => _timelineEvents;
+  String _message;
+  String get message => _message;
 
   // The possible 'kind' values.
   static const String kVMUpdate               = 'VMUpdate';
@@ -690,6 +709,11 @@ class ServiceEvent extends ServiceObject {
     // on a Stream.
     final List<dynamic> dynamicList = map['timelineEvents'];
     _timelineEvents = dynamicList?.cast<Map<String, dynamic>>();
+
+     final String base64Bytes = map['bytes'];
+     if (base64Bytes != null) {
+       _message = utf8.decode(base64.decode(base64Bytes)).trim();
+     }
   }
 
   bool get isPauseEvent {

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

@@ -68,6 +68,16 @@ void main() {
       Platform: () => macPlatform,
     });
 
+    testUsingContext('parses major version', () {
+      expect(IOSDevice('device-123', sdkVersion: '1.0.0').majorSdkVersion, 1);
+      expect(IOSDevice('device-123', sdkVersion: '13.1.1').majorSdkVersion, 13);
+      expect(IOSDevice('device-123', sdkVersion: '10').majorSdkVersion, 10);
+      expect(IOSDevice('device-123', sdkVersion: '0').majorSdkVersion, 0);
+      expect(IOSDevice('device-123', sdkVersion: 'bogus').majorSdkVersion, 0);
+    }, overrides: <Type, Generator>{
+      Platform: () => macPlatform,
+    });
+
     for (Platform platform in unsupportedPlatforms) {
       testUsingContext('throws UnsupportedError exception if instantiated on ${platform.operatingSystem}', () {
         expect(

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

@@ -9,6 +9,7 @@ import 'package:flutter_tools/src/artifacts.dart';
 import 'package:flutter_tools/src/base/common.dart';
 import 'package:flutter_tools/src/base/context.dart';
 import 'package:flutter_tools/src/base/file_system.dart';
+import 'package:flutter_tools/src/base/io.dart' as io;
 import 'package:flutter_tools/src/base/logger.dart';
 import 'package:flutter_tools/src/build_info.dart';
 import 'package:flutter_tools/src/compile.dart';
@@ -626,6 +627,23 @@ void main() {
   }, overrides: <Type, Generator>{
     FeatureFlags: () => TestFeatureFlags(isWebIncrementalCompilerEnabled: true),
   }));
+
+  test('connect sets up log reader', () => testbed.run(() async {
+    final MockDevice mockDevice = MockDevice();
+    final MockDeviceLogReader mockLogReader = MockDeviceLogReader();
+    when(mockDevice.getLogReader(app: anyNamed('app'))).thenReturn(mockLogReader);
+
+    final TestFlutterDevice flutterDevice = TestFlutterDevice(
+      mockDevice,
+      <FlutterView>[],
+      observatoryUris: <Uri>[ testUri ]
+    );
+
+    await flutterDevice.connect();
+    verify(mockLogReader.connectedVMServices = <VMService>[ mockVMService ]);
+  }, overrides: <Type, Generator>{
+    VMServiceConnector: () => (Uri httpUri, { ReloadSources reloadSources, Restart restart, CompileExpression compileExpression, io.CompressionOptions compression }) async => mockVMService,
+  }));
 }
 
 class MockFlutterDevice extends Mock implements FlutterDevice {}
@@ -634,15 +652,22 @@ class MockVMService extends Mock implements VMService {}
 class MockDevFS extends Mock implements DevFS {}
 class MockIsolate extends Mock implements Isolate {}
 class MockDevice extends Mock implements Device {}
+class MockDeviceLogReader extends Mock implements DeviceLogReader {}
 class MockUsage extends Mock implements Usage {}
 class MockProcessManager extends Mock implements ProcessManager {}
 class MockServiceEvent extends Mock implements ServiceEvent {}
 class TestFlutterDevice extends FlutterDevice {
-  TestFlutterDevice(Device device, this.views)
-    : super(device, buildMode: BuildMode.debug, trackWidgetCreation: false);
+  TestFlutterDevice(Device device, this.views, { List<Uri> observatoryUris })
+    : super(device, buildMode: BuildMode.debug, trackWidgetCreation: false) {
+    _observatoryUris = observatoryUris;
+  }
 
   @override
   final List<FlutterView> views;
+
+  @override
+  List<Uri> get observatoryUris => _observatoryUris;
+  List<Uri> _observatoryUris;
 }
 
 class ThrowingForwardingFileSystem extends ForwardingFileSystem {