Unverified Commit 2978b59b authored by Christopher Fujino's avatar Christopher Fujino Committed by GitHub

[flutter_tools] Dump backtrace on ios app startup timeout (#101610)

parent 0f2b1a3b
......@@ -434,6 +434,7 @@ class IOSDevice extends Device {
_logger.printTrace('Application launched on the device. Waiting for observatory url.');
final Timer timer = Timer(discoveryTimeout ?? const Duration(seconds: 30), () {
_logger.printError('iOS Observatory not discovered after 30 seconds. This is taking much longer than expected...');
iosDeployDebugger?.pauseDumpBacktraceResume();
});
final Uri? localUri = await observatoryDiscovery?.uri;
timer.cancel();
......
......@@ -296,12 +296,23 @@ class IOSDeployDebugger {
// (lldb) Process 6152 detached
static final RegExp _lldbProcessDetached = RegExp(r'Process \d* detached');
// (lldb) Process 6152 resuming
static final RegExp _lldbProcessResuming = RegExp(r'Process \d+ resuming');
// Send signal to stop (pause) the app. Used before a backtrace dump.
static const String _signalStop = 'process signal SIGSTOP';
static const String _processResume = 'process continue';
static const String _processInterrupt = 'process interrupt';
// Print backtrace for all threads while app is stopped.
static const String _backTraceAll = 'thread backtrace all';
/// If this is non-null, then the app process is paused and awaiting backtrace logging.
///
/// The future should be completed once the backtraces are logged.
Completer<void>? _processResumeCompleter;
/// Launch the app on the device, and attach the debugger.
///
/// Returns whether or not the debugger successfully attached.
......@@ -319,7 +330,6 @@ class IOSDeployDebugger {
.transform<String>(const LineSplitter())
.listen((String line) {
_monitorIOSDeployFailure(line, _logger);
// (lldb) run
// 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/
......@@ -350,6 +360,13 @@ class IOSDeployDebugger {
// Even though we're not "detached", just stopped, mark as detached so the backtrace
// is only show in verbose.
_debuggerState = _IOSDeployDebuggerState.detached;
// If we paused the app and are waiting to resume it, complete the completer
final Completer<void>? processResumeCompleter = _processResumeCompleter;
if (processResumeCompleter != null) {
_processResumeCompleter = null;
processResumeCompleter.complete();
}
return;
}
......@@ -357,9 +374,12 @@ class IOSDeployDebugger {
// The app has been stopped. Dump the backtrace, and detach.
_logger.printTrace(line);
_iosDeployProcess?.stdin.writeln(_backTraceAll);
detach();
if (_processResumeCompleter == null) {
detach();
}
return;
}
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.
......@@ -374,6 +394,13 @@ class IOSDeployDebugger {
return;
}
if (_lldbProcessResuming.hasMatch(line)) {
_logger.printTrace(line);
// we marked this detached when we received [_backTraceAll]
_debuggerState = _IOSDeployDebuggerState.attached;
return;
}
if (_debuggerState != _IOSDeployDebuggerState.attached) {
_logger.printTrace(line);
return;
......@@ -433,11 +460,28 @@ class IOSDeployDebugger {
return success;
}
Future<void> stopAndDumpBacktrace() async {
/// Pause app, dump backtrace for debugging, and resume.
Future<void> pauseDumpBacktraceResume() async {
if (!debuggerAttached) {
return;
}
final Completer<void> completer = Completer<void>();
_processResumeCompleter = completer;
try {
// Stop the app, which will prompt the backtrace to be printed for all threads in the stdoutSubscription handler.
_iosDeployProcess?.stdin.writeln(_processInterrupt);
} on SocketException catch (error) {
_logger.printTrace('Could not stop app from debugger: $error');
}
// wait for backtrace to be dumped
await completer.future;
_iosDeployProcess?.stdin.writeln(_processResume);
}
Future<void> stopAndDumpBacktrace() async {
if (!debuggerAttached) {
return;
}
try {
// Stop the app, which will prompt the backtrace to be printed for all threads in the stdoutSubscription handler.
_iosDeployProcess?.stdin.writeln(_signalStop);
......
......@@ -330,6 +330,71 @@ void main () {
'process detach',
]);
});
testWithoutContext('pause with backtrace', () async {
final StreamController<List<int>> stdin = StreamController<List<int>>();
final Stream<String> stdinStream = stdin.stream.transform<String>(const Utf8Decoder());
const String stdout = '''
(lldb) run
success
Log on attach
(lldb) Process 6156 stopped
* thread #1, stop reason = Assertion failed:
thread backtrace all
process continue
* thread #1, stop reason = signal SIGSTOP
* frame #0: 0x0000000102eaee80 dyld`dyld3::MachOFile::read_uleb128(Diagnostics&, unsigned char const*&, unsigned char const*) + 36
frame #1: 0x0000000102eabbd4 dyld`dyld3::MachOLoaded::trieWalk(Diagnostics&, unsigned char const*, unsigned char const*, char const*) + 332
frame #2: 0x0000000102eaa078 dyld`DyldSharedCache::hasImagePath(char const*, unsigned int&) const + 144
frame #3: 0x0000000102eaa13c dyld`DyldSharedCache::hasNonOverridablePath(char const*) const + 44
frame #4: 0x0000000102ebc404 dyld`dyld3::closure::ClosureBuilder::findImage(char const*, dyld3::closure::ClosureBuilder::LoadedImageChain const&, dyld3::closure::ClosureBuilder::BuilderLoadedImage*&, dyld3::closure::ClosureBuilder::LinkageType, unsigned int, bool) +
frame #5: 0x0000000102ebd974 dyld`invocation function for block in dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 136
frame #6: 0x0000000102eae1b0 dyld`invocation function for block in dyld3::MachOFile::forEachDependentDylib(void (char const*, bool, bool, bool, unsigned int, unsigned int, bool&) block_pointer) const + 136
frame #7: 0x0000000102eadc38 dyld`dyld3::MachOFile::forEachLoadCommand(Diagnostics&, void (load_command const*, bool&) block_pointer) const + 168
frame #8: 0x0000000102eae108 dyld`dyld3::MachOFile::forEachDependentDylib(void (char const*, bool, bool, bool, unsigned int, unsigned int, bool&) block_pointer) const + 116
frame #9: 0x0000000102ebd80c dyld`dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 164
frame #10: 0x0000000102ebd8a8 dyld`dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 320
frame #11: 0x0000000102ebd8a8 dyld`dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 320
frame #12: 0x0000000102ebd8a8 dyld`dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 320
frame #13: 0x0000000102ebd8a8 dyld`dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 320
frame #14: 0x0000000102ebd8a8 dyld`dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 320
frame #15: 0x0000000102ebd8a8 dyld`dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 320
frame #16: 0x0000000102ec7638 dyld`dyld3::closure::ClosureBuilder::makeLaunchClosure(dyld3::closure::LoadedFileInfo const&, bool) + 752
frame #17: 0x0000000102e8fcf0 dyld`dyld::buildLaunchClosure(unsigned char const*, dyld3::closure::LoadedFileInfo const&, char const**) + 344
frame #18: 0x0000000102e8e938 dyld`dyld::_main(macho_header const*, unsigned long, int, char const**, char const**, char const**, unsigned long*) + 2876
frame #19: 0x0000000102e8922c dyld`dyldbootstrap::start(dyld3::MachOLoaded const*, int, char const**, dyld3::MachOLoaded const*, unsigned long*) + 432
frame #20: 0x0000000102e89038 dyld`_dyld_start + 56
''';
final BufferLogger logger = BufferLogger.test();
final FakeProcessManager processManager = FakeProcessManager.list(<FakeCommand>[
FakeCommand(
command: const <String>[
'ios-deploy',
],
stdout: stdout,
stdin: IOSink(stdin.sink),
),
]);
final IOSDeployDebugger iosDeployDebugger = IOSDeployDebugger.test(
processManager: processManager,
logger: logger,
);
await iosDeployDebugger.launchAndAttach();
await iosDeployDebugger.pauseDumpBacktraceResume();
// verify stacktrace was logged to trace
expect(
logger.traceText,
contains(
'frame #0: 0x0000000102eaee80 dyld`dyld3::MachOFile::read_uleb128(Diagnostics&, unsigned char const*&, unsigned char const*) + 36',
),
);
expect(await stdinStream.take(3).toList(), <String>[
'thread backtrace all',
'\n',
'process detach',
]);
});
});
group('IOSDeploy.uninstallApp', () {
......
......@@ -5,10 +5,12 @@
// @dart = 2.8
import 'dart:async';
import 'dart:convert';
import 'package:file/memory.dart';
import 'package:flutter_tools/src/artifacts.dart';
import 'package:flutter_tools/src/base/file_system.dart';
import 'package:flutter_tools/src/base/io.dart';
import 'package:flutter_tools/src/base/logger.dart';
import 'package:flutter_tools/src/base/platform.dart';
import 'package:flutter_tools/src/build_info.dart';
......@@ -64,26 +66,35 @@ const FakeCommand kLaunchDebugCommand = FakeCommand(command: <String>[
});
// The command used to actually launch the app and attach the debugger with args in debug.
const FakeCommand kAttachDebuggerCommand = FakeCommand(command: <String>[
'script',
'-t',
'0',
'/dev/null',
'HostArtifact.iosDeploy',
'--id',
'123',
'--bundle',
'/',
'--debug',
'--no-wifi',
'--args',
'--enable-dart-profiling --disable-service-auth-codes --enable-checked-mode --verify-entry-points'
], environment: <String, String>{
'PATH': '/usr/bin:null',
'DYLD_LIBRARY_PATH': '/path/to/libraries',
},
stdout: '(lldb) run\nsuccess',
);
FakeCommand attachDebuggerCommand({
IOSink stdin,
Completer<void>/*?*/ completer,
}) {
return FakeCommand(
command: const <String>[
'script',
'-t',
'0',
'/dev/null',
'HostArtifact.iosDeploy',
'--id',
'123',
'--bundle',
'/',
'--debug',
'--no-wifi',
'--args',
'--enable-dart-profiling --disable-service-auth-codes --enable-checked-mode --verify-entry-points',
],
completer: completer,
environment: const <String, String>{
'PATH': '/usr/bin:null',
'DYLD_LIBRARY_PATH': '/path/to/libraries',
},
stdout: '(lldb) run\nsuccess',
stdin: stdin,
);
}
void main() {
testWithoutContext('disposing device disposes the portForwarder and logReader', () async {
......@@ -108,7 +119,7 @@ void main() {
testWithoutContext('IOSDevice.startApp attaches in debug mode via log reading on iOS 13+', () async {
final FileSystem fileSystem = MemoryFileSystem.test();
final FakeProcessManager processManager = FakeProcessManager.list(<FakeCommand>[
kAttachDebuggerCommand,
attachDebuggerCommand(),
]);
final IOSDevice device = setUpIOSDevice(
processManager: processManager,
......@@ -183,8 +194,10 @@ void main() {
testWithoutContext('IOSDevice.startApp prints warning message if discovery takes longer than configured timeout', () async {
final FileSystem fileSystem = MemoryFileSystem.test();
final BufferLogger logger = BufferLogger.test();
final CompleterIOSink stdin = CompleterIOSink();
final Completer<void> completer = Completer<void>();
final FakeProcessManager processManager = FakeProcessManager.list(<FakeCommand>[
kAttachDebuggerCommand,
attachDebuggerCommand(stdin: stdin, completer: completer),
]);
final IOSDevice device = setUpIOSDevice(
processManager: processManager,
......@@ -203,11 +216,8 @@ void main() {
device.setLogReader(iosApp, deviceLogReader);
// Start writing messages to the log reader.
Timer.run(() async {
await Future<void>.delayed(const Duration(milliseconds: 1));
deviceLogReader.addLine('Foo');
deviceLogReader.addLine('The Dart VM service is listening on http://127.0.0.1:456');
});
deviceLogReader.addLine('Foo');
deviceLogReader.addLine('The Dart VM service is listening on http://127.0.0.1:456');
final LaunchResult launchResult = await device.startApp(iosApp,
prebuiltApplication: true,
......@@ -220,6 +230,9 @@ void main() {
expect(launchResult.hasObservatory, true);
expect(await device.stopApp(iosApp), false);
expect(logger.errorText, contains('iOS Observatory not discovered after 30 seconds. This is taking much longer than expected...'));
expect(utf8.decoder.convert(stdin.writes.first), contains('process interrupt'));
completer.complete();
expect(processManager, hasNoRemainingExpectations);
});
testWithoutContext('IOSDevice.startApp succeeds in release mode', () async {
......
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