Skip to content

Commit 2978b59

Browse files
[flutter_tools] Dump backtrace on ios app startup timeout (#101610)
1 parent 0f2b1a3 commit 2978b59

File tree

4 files changed

+153
-30
lines changed

4 files changed

+153
-30
lines changed

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

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -434,6 +434,7 @@ class IOSDevice extends Device {
434434
_logger.printTrace('Application launched on the device. Waiting for observatory url.');
435435
final Timer timer = Timer(discoveryTimeout ?? const Duration(seconds: 30), () {
436436
_logger.printError('iOS Observatory not discovered after 30 seconds. This is taking much longer than expected...');
437+
iosDeployDebugger?.pauseDumpBacktraceResume();
437438
});
438439
final Uri? localUri = await observatoryDiscovery?.uri;
439440
timer.cancel();

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

Lines changed: 47 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -296,12 +296,23 @@ class IOSDeployDebugger {
296296
// (lldb) Process 6152 detached
297297
static final RegExp _lldbProcessDetached = RegExp(r'Process \d* detached');
298298

299+
// (lldb) Process 6152 resuming
300+
static final RegExp _lldbProcessResuming = RegExp(r'Process \d+ resuming');
301+
299302
// Send signal to stop (pause) the app. Used before a backtrace dump.
300303
static const String _signalStop = 'process signal SIGSTOP';
301304

305+
static const String _processResume = 'process continue';
306+
static const String _processInterrupt = 'process interrupt';
307+
302308
// Print backtrace for all threads while app is stopped.
303309
static const String _backTraceAll = 'thread backtrace all';
304310

311+
/// If this is non-null, then the app process is paused and awaiting backtrace logging.
312+
///
313+
/// The future should be completed once the backtraces are logged.
314+
Completer<void>? _processResumeCompleter;
315+
305316
/// Launch the app on the device, and attach the debugger.
306317
///
307318
/// Returns whether or not the debugger successfully attached.
@@ -319,7 +330,6 @@ class IOSDeployDebugger {
319330
.transform<String>(const LineSplitter())
320331
.listen((String line) {
321332
_monitorIOSDeployFailure(line, _logger);
322-
323333
// (lldb) run
324334
// success
325335
// 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,16 +360,26 @@ class IOSDeployDebugger {
350360
// Even though we're not "detached", just stopped, mark as detached so the backtrace
351361
// is only show in verbose.
352362
_debuggerState = _IOSDeployDebuggerState.detached;
363+
364+
// If we paused the app and are waiting to resume it, complete the completer
365+
final Completer<void>? processResumeCompleter = _processResumeCompleter;
366+
if (processResumeCompleter != null) {
367+
_processResumeCompleter = null;
368+
processResumeCompleter.complete();
369+
}
353370
return;
354371
}
355372

356373
if (line.contains('PROCESS_STOPPED') || _lldbProcessStopped.hasMatch(line)) {
357374
// The app has been stopped. Dump the backtrace, and detach.
358375
_logger.printTrace(line);
359376
_iosDeployProcess?.stdin.writeln(_backTraceAll);
360-
detach();
377+
if (_processResumeCompleter == null) {
378+
detach();
379+
}
361380
return;
362381
}
382+
363383
if (line.contains('PROCESS_EXITED') || _lldbProcessExit.hasMatch(line)) {
364384
// The app exited or crashed, so exit. Continue passing debugging
365385
// messages to the log reader until it exits to capture crash dumps.
@@ -374,6 +394,13 @@ class IOSDeployDebugger {
374394
return;
375395
}
376396

397+
if (_lldbProcessResuming.hasMatch(line)) {
398+
_logger.printTrace(line);
399+
// we marked this detached when we received [_backTraceAll]
400+
_debuggerState = _IOSDeployDebuggerState.attached;
401+
return;
402+
}
403+
377404
if (_debuggerState != _IOSDeployDebuggerState.attached) {
378405
_logger.printTrace(line);
379406
return;
@@ -433,11 +460,28 @@ class IOSDeployDebugger {
433460
return success;
434461
}
435462

436-
Future<void> stopAndDumpBacktrace() async {
463+
/// Pause app, dump backtrace for debugging, and resume.
464+
Future<void> pauseDumpBacktraceResume() async {
437465
if (!debuggerAttached) {
438466
return;
439467
}
468+
final Completer<void> completer = Completer<void>();
469+
_processResumeCompleter = completer;
470+
try {
471+
// Stop the app, which will prompt the backtrace to be printed for all threads in the stdoutSubscription handler.
472+
_iosDeployProcess?.stdin.writeln(_processInterrupt);
473+
} on SocketException catch (error) {
474+
_logger.printTrace('Could not stop app from debugger: $error');
475+
}
476+
// wait for backtrace to be dumped
477+
await completer.future;
478+
_iosDeployProcess?.stdin.writeln(_processResume);
479+
}
440480

481+
Future<void> stopAndDumpBacktrace() async {
482+
if (!debuggerAttached) {
483+
return;
484+
}
441485
try {
442486
// Stop the app, which will prompt the backtrace to be printed for all threads in the stdoutSubscription handler.
443487
_iosDeployProcess?.stdin.writeln(_signalStop);

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

Lines changed: 65 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -330,6 +330,71 @@ void main () {
330330
'process detach',
331331
]);
332332
});
333+
334+
testWithoutContext('pause with backtrace', () async {
335+
final StreamController<List<int>> stdin = StreamController<List<int>>();
336+
final Stream<String> stdinStream = stdin.stream.transform<String>(const Utf8Decoder());
337+
const String stdout = '''
338+
(lldb) run
339+
success
340+
Log on attach
341+
(lldb) Process 6156 stopped
342+
* thread #1, stop reason = Assertion failed:
343+
thread backtrace all
344+
process continue
345+
* thread #1, stop reason = signal SIGSTOP
346+
* frame #0: 0x0000000102eaee80 dyld`dyld3::MachOFile::read_uleb128(Diagnostics&, unsigned char const*&, unsigned char const*) + 36
347+
frame #1: 0x0000000102eabbd4 dyld`dyld3::MachOLoaded::trieWalk(Diagnostics&, unsigned char const*, unsigned char const*, char const*) + 332
348+
frame #2: 0x0000000102eaa078 dyld`DyldSharedCache::hasImagePath(char const*, unsigned int&) const + 144
349+
frame #3: 0x0000000102eaa13c dyld`DyldSharedCache::hasNonOverridablePath(char const*) const + 44
350+
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) +
351+
352+
frame #5: 0x0000000102ebd974 dyld`invocation function for block in dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 136
353+
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
354+
frame #7: 0x0000000102eadc38 dyld`dyld3::MachOFile::forEachLoadCommand(Diagnostics&, void (load_command const*, bool&) block_pointer) const + 168
355+
frame #8: 0x0000000102eae108 dyld`dyld3::MachOFile::forEachDependentDylib(void (char const*, bool, bool, bool, unsigned int, unsigned int, bool&) block_pointer) const + 116
356+
frame #9: 0x0000000102ebd80c dyld`dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 164
357+
frame #10: 0x0000000102ebd8a8 dyld`dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 320
358+
frame #11: 0x0000000102ebd8a8 dyld`dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 320
359+
frame #12: 0x0000000102ebd8a8 dyld`dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 320
360+
frame #13: 0x0000000102ebd8a8 dyld`dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 320
361+
frame #14: 0x0000000102ebd8a8 dyld`dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 320
362+
frame #15: 0x0000000102ebd8a8 dyld`dyld3::closure::ClosureBuilder::recursiveLoadDependents(dyld3::closure::ClosureBuilder::LoadedImageChain&, bool) + 320
363+
frame #16: 0x0000000102ec7638 dyld`dyld3::closure::ClosureBuilder::makeLaunchClosure(dyld3::closure::LoadedFileInfo const&, bool) + 752
364+
frame #17: 0x0000000102e8fcf0 dyld`dyld::buildLaunchClosure(unsigned char const*, dyld3::closure::LoadedFileInfo const&, char const**) + 344
365+
frame #18: 0x0000000102e8e938 dyld`dyld::_main(macho_header const*, unsigned long, int, char const**, char const**, char const**, unsigned long*) + 2876
366+
frame #19: 0x0000000102e8922c dyld`dyldbootstrap::start(dyld3::MachOLoaded const*, int, char const**, dyld3::MachOLoaded const*, unsigned long*) + 432
367+
frame #20: 0x0000000102e89038 dyld`_dyld_start + 56
368+
''';
369+
final BufferLogger logger = BufferLogger.test();
370+
final FakeProcessManager processManager = FakeProcessManager.list(<FakeCommand>[
371+
FakeCommand(
372+
command: const <String>[
373+
'ios-deploy',
374+
],
375+
stdout: stdout,
376+
stdin: IOSink(stdin.sink),
377+
),
378+
]);
379+
final IOSDeployDebugger iosDeployDebugger = IOSDeployDebugger.test(
380+
processManager: processManager,
381+
logger: logger,
382+
);
383+
await iosDeployDebugger.launchAndAttach();
384+
await iosDeployDebugger.pauseDumpBacktraceResume();
385+
// verify stacktrace was logged to trace
386+
expect(
387+
logger.traceText,
388+
contains(
389+
'frame #0: 0x0000000102eaee80 dyld`dyld3::MachOFile::read_uleb128(Diagnostics&, unsigned char const*&, unsigned char const*) + 36',
390+
),
391+
);
392+
expect(await stdinStream.take(3).toList(), <String>[
393+
'thread backtrace all',
394+
'\n',
395+
'process detach',
396+
]);
397+
});
333398
});
334399

335400
group('IOSDeploy.uninstallApp', () {

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

Lines changed: 40 additions & 27 deletions
Original file line numberDiff line numberDiff line change
@@ -5,10 +5,12 @@
55
// @dart = 2.8
66

77
import 'dart:async';
8+
import 'dart:convert';
89

910
import 'package:file/memory.dart';
1011
import 'package:flutter_tools/src/artifacts.dart';
1112
import 'package:flutter_tools/src/base/file_system.dart';
13+
import 'package:flutter_tools/src/base/io.dart';
1214
import 'package:flutter_tools/src/base/logger.dart';
1315
import 'package:flutter_tools/src/base/platform.dart';
1416
import 'package:flutter_tools/src/build_info.dart';
@@ -64,26 +66,35 @@ const FakeCommand kLaunchDebugCommand = FakeCommand(command: <String>[
6466
});
6567

6668
// The command used to actually launch the app and attach the debugger with args in debug.
67-
const FakeCommand kAttachDebuggerCommand = FakeCommand(command: <String>[
68-
'script',
69-
'-t',
70-
'0',
71-
'/dev/null',
72-
'HostArtifact.iosDeploy',
73-
'--id',
74-
'123',
75-
'--bundle',
76-
'/',
77-
'--debug',
78-
'--no-wifi',
79-
'--args',
80-
'--enable-dart-profiling --disable-service-auth-codes --enable-checked-mode --verify-entry-points'
81-
], environment: <String, String>{
82-
'PATH': '/usr/bin:null',
83-
'DYLD_LIBRARY_PATH': '/path/to/libraries',
84-
},
85-
stdout: '(lldb) run\nsuccess',
86-
);
69+
FakeCommand attachDebuggerCommand({
70+
IOSink stdin,
71+
Completer<void>/*?*/ completer,
72+
}) {
73+
return FakeCommand(
74+
command: const <String>[
75+
'script',
76+
'-t',
77+
'0',
78+
'/dev/null',
79+
'HostArtifact.iosDeploy',
80+
'--id',
81+
'123',
82+
'--bundle',
83+
'/',
84+
'--debug',
85+
'--no-wifi',
86+
'--args',
87+
'--enable-dart-profiling --disable-service-auth-codes --enable-checked-mode --verify-entry-points',
88+
],
89+
completer: completer,
90+
environment: const <String, String>{
91+
'PATH': '/usr/bin:null',
92+
'DYLD_LIBRARY_PATH': '/path/to/libraries',
93+
},
94+
stdout: '(lldb) run\nsuccess',
95+
stdin: stdin,
96+
);
97+
}
8798

8899
void main() {
89100
testWithoutContext('disposing device disposes the portForwarder and logReader', () async {
@@ -108,7 +119,7 @@ void main() {
108119
testWithoutContext('IOSDevice.startApp attaches in debug mode via log reading on iOS 13+', () async {
109120
final FileSystem fileSystem = MemoryFileSystem.test();
110121
final FakeProcessManager processManager = FakeProcessManager.list(<FakeCommand>[
111-
kAttachDebuggerCommand,
122+
attachDebuggerCommand(),
112123
]);
113124
final IOSDevice device = setUpIOSDevice(
114125
processManager: processManager,
@@ -183,8 +194,10 @@ void main() {
183194
testWithoutContext('IOSDevice.startApp prints warning message if discovery takes longer than configured timeout', () async {
184195
final FileSystem fileSystem = MemoryFileSystem.test();
185196
final BufferLogger logger = BufferLogger.test();
197+
final CompleterIOSink stdin = CompleterIOSink();
198+
final Completer<void> completer = Completer<void>();
186199
final FakeProcessManager processManager = FakeProcessManager.list(<FakeCommand>[
187-
kAttachDebuggerCommand,
200+
attachDebuggerCommand(stdin: stdin, completer: completer),
188201
]);
189202
final IOSDevice device = setUpIOSDevice(
190203
processManager: processManager,
@@ -203,11 +216,8 @@ void main() {
203216
device.setLogReader(iosApp, deviceLogReader);
204217

205218
// Start writing messages to the log reader.
206-
Timer.run(() async {
207-
await Future<void>.delayed(const Duration(milliseconds: 1));
208-
deviceLogReader.addLine('Foo');
209-
deviceLogReader.addLine('The Dart VM service is listening on http://127.0.0.1:456');
210-
});
219+
deviceLogReader.addLine('Foo');
220+
deviceLogReader.addLine('The Dart VM service is listening on http://127.0.0.1:456');
211221

212222
final LaunchResult launchResult = await device.startApp(iosApp,
213223
prebuiltApplication: true,
@@ -220,6 +230,9 @@ void main() {
220230
expect(launchResult.hasObservatory, true);
221231
expect(await device.stopApp(iosApp), false);
222232
expect(logger.errorText, contains('iOS Observatory not discovered after 30 seconds. This is taking much longer than expected...'));
233+
expect(utf8.decoder.convert(stdin.writes.first), contains('process interrupt'));
234+
completer.complete();
235+
expect(processManager, hasNoRemainingExpectations);
223236
});
224237

225238
testWithoutContext('IOSDevice.startApp succeeds in release mode', () async {

0 commit comments

Comments
 (0)