Commit dd7e3133 authored by Chris Bracken's avatar Chris Bracken Committed by GitHub

Migrate to os_log for reading iOS simulator logs (#12079)

1. Migrate simulator device log tailing to os_log toolchain
2. When the log tag (component) is available (iOS 11/Xcode 9), filter to
   the set of log lines with tag 'Flutter'.

As of iOS 11 / Xcode 9, Flutter engine logs are no longer recorded in the
simulator's syslog file, which we previously read using tail -f. Instead
they're now accessible through Apple's new macOS/iOS os_log facility,
via /usr/bin/log, which supports a relatively flexible query language.

When run in non-interactive mode, /usr/bin/log buffers its output in 4k
chunks, which is significantly smaller than what's emitted up to the
point where the observatory/diagnostics port information is logged. As a
workaround we force it to run in interactive mode via the script tool.
parent 016f9390
...@@ -486,6 +486,36 @@ class IOSSimulator extends Device { ...@@ -486,6 +486,36 @@ class IOSSimulator extends Device {
} }
} }
final RegExp _iosSdkRegExp = new RegExp(r'iOS (\d+)');
/// Launches the device log reader process on the host.
Future<Process> launchDeviceLogTool(IOSSimulator device) async {
final Match sdkMatch = _iosSdkRegExp.firstMatch(await device.sdkNameAndVersion);
final int majorVersion = int.parse(sdkMatch.group(1) ?? 11);
// Versions of iOS prior to iOS 11 log to the simulator syslog file.
if (majorVersion < 11)
return runCommand(<String>['tail', '-n', '0', '-F', device.logFilePath]);
// For iOS 11 and above, use /usr/bin/log to tail process logs.
// Run in interactive mode (via script), otherwise /usr/bin/log buffers in 4k chunks. (radar: 34420207)
return runCommand(<String>[
'script', '/dev/null', '/usr/bin/log', 'stream', '--style', 'syslog', '--predicate', 'processImagePath CONTAINS "${device.id}"',
]);
}
Future<Process> launchSystemLogTool(IOSSimulator device) async {
final Match sdkMatch = _iosSdkRegExp.firstMatch(await device.sdkNameAndVersion);
final int majorVersion = int.parse(sdkMatch.group(1) ?? 11);
// Versions of iOS prior to 11 tail the simulator syslog file.
if (majorVersion < 11)
return runCommand(<String>['tail', '-n', '0', '-F', '/private/var/log/system.log']);
// For iOS 11 and later, all relevant detail is in the device log.
return null;
}
class _IOSSimulatorLogReader extends DeviceLogReader { class _IOSSimulatorLogReader extends DeviceLogReader {
String _appName; String _appName;
...@@ -514,15 +544,17 @@ class _IOSSimulatorLogReader extends DeviceLogReader { ...@@ -514,15 +544,17 @@ class _IOSSimulatorLogReader extends DeviceLogReader {
Future<Null> _start() async { Future<Null> _start() async {
// Device log. // Device log.
device.ensureLogsExists(); device.ensureLogsExists();
_deviceProcess = await runCommand(<String>['tail', '-n', '0', '-F', device.logFilePath]); _deviceProcess = await launchDeviceLogTool(device);
_deviceProcess.stdout.transform(UTF8.decoder).transform(const LineSplitter()).listen(_onDeviceLine); _deviceProcess.stdout.transform(UTF8.decoder).transform(const LineSplitter()).listen(_onDeviceLine);
_deviceProcess.stderr.transform(UTF8.decoder).transform(const LineSplitter()).listen(_onDeviceLine); _deviceProcess.stderr.transform(UTF8.decoder).transform(const LineSplitter()).listen(_onDeviceLine);
// Track system.log crashes. // Track system.log crashes.
// ReportCrash[37965]: Saved crash report for FlutterRunner[37941]... // ReportCrash[37965]: Saved crash report for FlutterRunner[37941]...
_systemProcess = await runCommand(<String>['tail', '-n', '0', '-F', '/private/var/log/system.log']); _systemProcess = await launchSystemLogTool(device);
if (_systemProcess != null) {
_systemProcess.stdout.transform(UTF8.decoder).transform(const LineSplitter()).listen(_onSystemLine); _systemProcess.stdout.transform(UTF8.decoder).transform(const LineSplitter()).listen(_onSystemLine);
_systemProcess.stderr.transform(UTF8.decoder).transform(const LineSplitter()).listen(_onSystemLine); _systemProcess.stderr.transform(UTF8.decoder).transform(const LineSplitter()).listen(_onSystemLine);
}
_deviceProcess.exitCode.whenComplete(() { _deviceProcess.exitCode.whenComplete(() {
if (_linesController.hasListener) if (_linesController.hasListener)
...@@ -531,8 +563,9 @@ class _IOSSimulatorLogReader extends DeviceLogReader { ...@@ -531,8 +563,9 @@ class _IOSSimulatorLogReader extends DeviceLogReader {
} }
// Match the log prefix (in order to shorten it): // Match the log prefix (in order to shorten it):
// 'Jan 29 01:31:44 devoncarew-macbookpro3 SpringBoard[96648]: ...' // * Xcode 8: Sep 13 15:28:51 cbracken-macpro localhost Runner[37195]: (Flutter) Observatory listening on http://127.0.0.1:57701/
static final RegExp _mapRegex = new RegExp(r'\S+ +\S+ +\S+ \S+ (.+)\[\d+\]\)?: (.*)$'); // * Xcode 9: 2017-09-13 15:26:57.228948-0700 localhost Runner[37195]: (Flutter) Observatory listening on http://127.0.0.1:57701/
static final RegExp _mapRegex = new RegExp(r'\S+ +\S+ +\S+ +(\S+ +)?(\S+)\[\d+\]\)?: (\(.*\))? *(.*)$');
// Jan 31 19:23:28 --- last message repeated 1 time --- // Jan 31 19:23:28 --- last message repeated 1 time ---
static final RegExp _lastMessageSingleRegex = new RegExp(r'\S+ +\S+ +\S+ --- last message repeated 1 time ---$'); static final RegExp _lastMessageSingleRegex = new RegExp(r'\S+ +\S+ +\S+ --- last message repeated 1 time ---$');
...@@ -540,46 +573,29 @@ class _IOSSimulatorLogReader extends DeviceLogReader { ...@@ -540,46 +573,29 @@ class _IOSSimulatorLogReader extends DeviceLogReader {
static final RegExp _flutterRunnerRegex = new RegExp(r' FlutterRunner\[\d+\] '); static final RegExp _flutterRunnerRegex = new RegExp(r' FlutterRunner\[\d+\] ');
/// List of log categories to always show in the logs, even if this is an app-specific
/// [DeviceLogReader]. Add to this list to make the log output more verbose.
static final List<String> _whitelistedLogCategories = <String>[
'CoreSimulatorBridge',
];
String _filterDeviceLine(String string) { String _filterDeviceLine(String string) {
final Match match = _mapRegex.matchAsPrefix(string); final Match match = _mapRegex.matchAsPrefix(string);
if (match != null) { if (match != null) {
final String category = match.group(1); final String category = match.group(2);
final String content = match.group(2); final String tag = match.group(3);
final String content = match.group(4);
// Filter out some messages that clearly aren't related to Flutter. // Filter out non-Flutter originated noise from the engine.
if (string.contains(': could not find icon for representation -> com.apple.')) if (category != 'Runner')
return null;
if (category == 'CoreSimulatorBridge'
&& content.startsWith('Pasteboard change listener callback port'))
return null;
if (category == 'routined'
&& content.startsWith('CoreLocation: Error occurred while trying to retrieve motion state update'))
return null; return null;
if (category == 'syslogd' && content == 'ASL Sender Statistics') if (tag != null && tag != '(Flutter)')
return null; return null;
// assertiond: assertion failed: 15E65 13E230: assertiond + 15801 [3C808658-78EC-3950-A264-79A64E0E463B]: 0x1 // Filter out some messages that clearly aren't related to Flutter.
if (category == 'assertiond' if (string.contains(': could not find icon for representation -> com.apple.'))
&& content.startsWith('assertion failed: ')
&& content.endsWith(']: 0x1'))
return null; return null;
// assertion failed: 15G1212 13E230: libxpc.dylib + 57882 [66C28065-C9DB-3C8E-926F-5A40210A6D1B]: 0x7d // assertion failed: 15G1212 13E230: libxpc.dylib + 57882 [66C28065-C9DB-3C8E-926F-5A40210A6D1B]: 0x7d
if (category == 'Runner' if (content.startsWith('assertion failed: ') && content.contains(' libxpc.dylib '))
&& content.startsWith('assertion failed: ')
&& content.contains(' libxpc.dylib '))
return null; return null;
if (_appName == null || _whitelistedLogCategories.contains(category)) if (_appName == null)
return '$category: $content'; return '$category: $content';
else if (category == _appName) else if (category == _appName)
return content; return content;
...@@ -587,6 +603,12 @@ class _IOSSimulatorLogReader extends DeviceLogReader { ...@@ -587,6 +603,12 @@ class _IOSSimulatorLogReader extends DeviceLogReader {
return null; return null;
} }
if (string.startsWith('Filtering the log data using '))
return null;
if (string.startsWith('Timestamp (process)[PID]'))
return null;
if (_lastMessageSingleRegex.matchAsPrefix(string) != null) if (_lastMessageSingleRegex.matchAsPrefix(string) != null)
return null; return null;
......
import 'dart:async'; import 'dart:async';
import 'dart:io' show ProcessResult; import 'dart:io' show ProcessResult, Process;
import 'package:file/file.dart'; import 'package:file/file.dart';
import 'package:flutter_tools/src/base/file_system.dart'; import 'package:flutter_tools/src/base/file_system.dart';
...@@ -15,6 +15,7 @@ import '../src/context.dart'; ...@@ -15,6 +15,7 @@ import '../src/context.dart';
class MockXcode extends Mock implements Xcode {} class MockXcode extends Mock implements Xcode {}
class MockFile extends Mock implements File {} class MockFile extends Mock implements File {}
class MockProcessManager extends Mock implements ProcessManager {} class MockProcessManager extends Mock implements ProcessManager {}
class MockProcess extends Mock implements Process {}
void main() { void main() {
final FakePlatform osx = new FakePlatform.fromPlatform(const LocalPlatform()); final FakePlatform osx = new FakePlatform.fromPlatform(const LocalPlatform());
...@@ -177,4 +178,69 @@ void main() { ...@@ -177,4 +178,69 @@ void main() {
} }
); );
}); });
group('launchDeviceLogTool', () {
MockProcessManager mockProcessManager;
setUp(() {
mockProcessManager = new MockProcessManager();
when(mockProcessManager.start(any, environment: null, workingDirectory: null))
.thenReturn(new Future<Process>.value(new MockProcess()));
});
testUsingContext('uses tail on iOS versions prior to iOS 11', () async {
final IOSSimulator device = new IOSSimulator('x', name: 'iPhone SE', category: 'iOS 9.3');
await launchDeviceLogTool(device);
expect(
verify(mockProcessManager.start(captureAny, environment: null, workingDirectory: null)).captured.single,
contains('tail'),
);
},
overrides: <Type, Generator>{
ProcessManager: () => mockProcessManager,
});
testUsingContext('uses /usr/bin/log on iOS 11 and above', () async {
final IOSSimulator device = new IOSSimulator('x', name: 'iPhone SE', category: 'iOS 11.0');
await launchDeviceLogTool(device);
expect(
verify(mockProcessManager.start(captureAny, environment: null, workingDirectory: null)).captured.single,
contains('/usr/bin/log'),
);
},
overrides: <Type, Generator>{
ProcessManager: () => mockProcessManager,
});
});
group('launchSystemLogTool', () {
MockProcessManager mockProcessManager;
setUp(() {
mockProcessManager = new MockProcessManager();
when(mockProcessManager.start(any, environment: null, workingDirectory: null))
.thenReturn(new Future<Process>.value(new MockProcess()));
});
testUsingContext('uses tail on iOS versions prior to iOS 11', () async {
final IOSSimulator device = new IOSSimulator('x', name: 'iPhone SE', category: 'iOS 9.3');
await launchSystemLogTool(device);
expect(
verify(mockProcessManager.start(captureAny, environment: null, workingDirectory: null)).captured.single,
contains('tail'),
);
},
overrides: <Type, Generator>{
ProcessManager: () => mockProcessManager,
});
testUsingContext('uses /usr/bin/log on iOS 11 and above', () async {
final IOSSimulator device = new IOSSimulator('x', name: 'iPhone SE', category: 'iOS 11.0');
await launchSystemLogTool(device);
verifyNever(mockProcessManager.start(any, environment: null, workingDirectory: null));
},
overrides: <Type, Generator>{
ProcessManager: () => mockProcessManager,
});
});
} }
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment