Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
22 changes: 21 additions & 1 deletion README.md
Original file line number Diff line number Diff line change
Expand Up @@ -616,6 +616,24 @@ and the second engine runs `start()` again. So the assertion is on everything
that reached the receiver over the launch, and the start-up line's "recovered
N" is required to say exactly one only when the activity was not relaunched.

A fresh install includes the OS having forgotten the last one. `adb uninstall`
returns when the package manager is done, not the activity manager: that drops
the uninstalled package's exit records when the removal broadcast reaches it,
and it drops them by package *name*, so the next install's record goes too if
that install has already crashed. The broadcast usually lands within two
seconds; on a loaded emulator it has taken about 16 and 17 seconds, after the
new install had crashed and the OS had filed it, and the launch that followed
read nothing (`received []`). So the harness dumps the exit history before it
uninstalls, and after the uninstall waits, every half second for at most two
minutes, until the dump lists no record and the OS has written its history
since. It prints `previous install left the exit history after <ms> ms`, and a
run that shows ten seconds or more there is one the harness used to be exposed
to. That wait is on the OS's own state, not a retry, and no assertion is relaxed
by it; `--upgrade-apk` needs none, because an update is a replacing install and
the same receiver ignores it. When a run still comes back without its record,
its failure says whether the OS still holds it (the app lost it) or no longer
does.

```bash
cd example && flutter pub get && flutter create --platforms=android . && cd ..
dart run tool/android-crash-harness.dart --device emulator-5554
Expand Down Expand Up @@ -657,7 +675,9 @@ crash arrive twice) and how it stays fixed; the window is tens of milliseconds
wide and moves with the machine, so sweep it rather than trust one value.

The receiver (`tool/otlp-log-sink.dart`) decodes OTLP by hand and is
unit-tested against the SDK's own encoder.
unit-tested against the SDK's own encoder, and what the harness reads out of
the OS's exit history (`tool/exit-info.dart`) is unit-tested against dumps
captured from the CI emulators.

**The ANR needs two things a bare block does not give.** An ANR is declared
only when something is *waiting* on the blocked main thread, so the script sends
Expand Down
232 changes: 232 additions & 0 deletions test/exit-info_test.dart
Original file line number Diff line number Diff line change
@@ -0,0 +1,232 @@
// The Android crash harness reads the OS's exit history (`dumpsys activity
// exit-info`) to know when a record has been filed and when the previous
// install's history is gone. These are the pure readings of that dump, checked
// against dumps captured from the CI emulators.
import 'package:flutter_test/flutter_test.dart';

import '../tool/exit-info.dart';

/// The dump at the end of a passing native case (artifact `art51`, repeat run
/// 1, API 34): the crash is filed under pid 8036 as reason 5, then two force
/// stops, newest first, all for uid 10197.
const String _kept = '''
ACTIVITY MANAGER PROCESS EXIT INFO (dumpsys activity exit-info)
Last Timestamp of Persistence Into Persistent Storage: 2026-10-08 22:49:04.298
package: com.example.otel_zone_example
Historical Process Exit for uid=10197
ApplicationExitInfo #0:
timestamp=2026-10-08 22:49:31.375 pid=8297 realUid=10197 packageUid=10197 definingUid=10197 user=0
process=com.example.otel_zone_example reason=10 (USER REQUESTED) subreason=21 (FORCE STOP) status=0
importance=100 pss=0.00 rss=0.00 description=stop com.example.otel_zone_example due to from pid 8396 state=46 bytes trace=null
ApplicationExitInfo #1:
timestamp=2026-10-08 22:49:23.372 pid=8180 realUid=10197 packageUid=10197 definingUid=10197 user=0
process=com.example.otel_zone_example reason=10 (USER REQUESTED) subreason=21 (FORCE STOP) status=0
importance=100 pss=0.00 rss=0.00 description=stop com.example.otel_zone_example due to from pid 8283 state=46 bytes trace=null
ApplicationExitInfo #2:
timestamp=2026-10-08 22:49:14.248 pid=8036 realUid=10197 packageUid=10197 definingUid=10197 user=0
process=com.example.otel_zone_example reason=5 (APP CRASH(NATIVE)) subreason=0 (UNKNOWN) status=11
importance=100 pss=0.00 rss=0.00 description=crash state=46 bytes trace=null
''';

/// The dump at the end of the failing native case (artifact `art49`, job
/// 113560596835, API 34). The app crashed as pid 5059 and the OS filed it at
/// 22:04:09; this is what was left at 22:05:57. Only the force stops remain
/// under the new install's uid, and the persistence timestamp is the moment
/// the previous install's removal landed.
const String _lost = '''
ACTIVITY MANAGER PROCESS EXIT INFO (dumpsys activity exit-info)
Last Timestamp of Persistence Into Persistent Storage: 2026-10-08 22:04:11.860
package: com.example.otel_zone_example
Historical Process Exit for uid=10193
ApplicationExitInfo #0:
timestamp=2026-10-08 22:05:57.008 pid=7414 realUid=10193 packageUid=10193 definingUid=10193 user=0
process=com.example.otel_zone_example reason=10 (USER REQUESTED) subreason=21 (FORCE STOP) status=0
importance=100 pss=0.00 rss=0.00 description=stop com.example.otel_zone_example due to from pid 7506 state=46 bytes trace=null
ApplicationExitInfo #1:
timestamp=2026-10-08 22:05:49.166 pid=5246 realUid=10193 packageUid=10193 definingUid=10193 user=0
process=com.example.otel_zone_example reason=10 (USER REQUESTED) subreason=21 (FORCE STOP) status=0
importance=100 pss=221MB rss=304MB description=stop com.example.otel_zone_example due to from pid 7397 state=46 bytes trace=null
''';

/// The dump of the install that the failing run replaced (artifact `art49`,
/// the `jvm` case before it, uid 10192): a crash and two force stops, and a
/// timestamp of the epoch because nothing had been persisted since boot.
const String _previousInstall = '''
ACTIVITY MANAGER PROCESS EXIT INFO (dumpsys activity exit-info)
Last Timestamp of Persistence Into Persistent Storage: 1970-01-01 00:00:00.000
package: com.example.otel_zone_example
Historical Process Exit for uid=10192
ApplicationExitInfo #0:
timestamp=2026-10-08 22:03:54.743 pid=4719 realUid=10192 packageUid=10192 definingUid=10192 user=0
process=com.example.otel_zone_example reason=10 (USER REQUESTED) subreason=21 (FORCE STOP) status=0
importance=100 pss=0.00 rss=0.00 description=stop com.example.otel_zone_example due to from pid 4985 state=46 bytes trace=null
ApplicationExitInfo #1:
timestamp=2026-10-08 22:03:43.342 pid=4192 realUid=10192 packageUid=10192 definingUid=10192 user=0
process=com.example.otel_zone_example reason=10 (USER REQUESTED) subreason=21 (FORCE STOP) status=0
importance=100 pss=208MB rss=289MB description=stop com.example.otel_zone_example due to from pid 4697 state=46 bytes trace=null
ApplicationExitInfo #2:
timestamp=2026-10-08 22:03:27.665 pid=3212 realUid=10192 packageUid=10192 definingUid=10192 user=0
process=com.example.otel_zone_example reason=4 (APP CRASH(EXCEPTION)) subreason=0 (UNKNOWN) status=0
importance=100 pss=0.00 rss=0.00 description=crash state=46 bytes trace=null
''';

/// What `dumpsys activity exit-info <package>` prints once the OS has dropped
/// the package: the two header lines the dump always starts with, and nothing
/// else. The OS prints a package's section only while it holds one. No dump was
/// captured at that moment, so this is the captured header with the timestamp
/// that the failing run's removal wrote (the one in [_lost]).
const String _removed = '''
ACTIVITY MANAGER PROCESS EXIT INFO (dumpsys activity exit-info)
Last Timestamp of Persistence Into Persistent Storage: 2026-10-08 22:04:11.860
''';

/// The same header, an older persistence: the app had no history when it was
/// uninstalled, and the OS has not yet processed the removal.
const String _emptyBefore = '''
ACTIVITY MANAGER PROCESS EXIT INFO (dumpsys activity exit-info)
Last Timestamp of Persistence Into Persistent Storage: 2026-10-08 22:03:30.120
''';

void main() {
group('holdsExitRecords', () {
test('is true for a dump that lists records', () {
expect(holdsExitRecords(_kept), isTrue);
expect(holdsExitRecords(_previousInstall), isTrue);
});

test('is false for a dump of only the header', () {
expect(holdsExitRecords(_removed), isFalse);
expect(holdsExitRecords(''), isFalse);
});
});

group('exitInfoPersistedAt', () {
test('reads the timestamp as the OS prints it', () {
expect(exitInfoPersistedAt(_kept), '2026-10-08 22:49:04.298');
expect(exitInfoPersistedAt(_removed), '2026-10-08 22:04:11.860');
});

test('reads the epoch of a boot that has persisted nothing', () {
expect(exitInfoPersistedAt(_previousInstall), '1970-01-01 00:00:00.000');
});

test('throws when the line is missing, rather than guess', () {
expect(
() => exitInfoPersistedAt(
'ACTIVITY MANAGER PROCESS EXIT INFO (dumpsys activity exit-info)\n',
),
throwsFormatException,
);
expect(() => exitInfoPersistedAt(''), throwsFormatException);
});
});

group('holdsExitRecord', () {
test('finds the native crash of pid 8036 as reason 5', () {
expect(holdsExitRecord(_kept, 8036, 5), isTrue);
});

test('does not find pid 8036 under another reason', () {
expect(holdsExitRecord(_kept, 8036, 10), isFalse);
expect(holdsExitRecord(_kept, 8036, 4), isFalse);
});

test('never reads across two records', () {
// pid 8180 is a force stop (reason 10); the reason-5 line that follows
// it in the dump belongs to pid 8036.
expect(holdsExitRecord(_kept, 8180, 5), isFalse);
expect(holdsExitRecord(_kept, 8297, 5), isFalse);
expect(holdsExitRecord(_kept, 8180, 10), isTrue);
});

test('matches the whole pid, not a prefix of it', () {
expect(holdsExitRecord(_kept, 803, 5), isFalse);
expect(holdsExitRecord(_kept, 80361, 5), isFalse);
});

test('does not mistake reason 5 for reason 15 or 50', () {
final String other = _kept.replaceFirst('reason=5 (', 'reason=15 (');
expect(holdsExitRecord(other, 8036, 5), isFalse);
expect(holdsExitRecord(other, 8036, 15), isTrue);
});

test('has nothing to find in the dump that lost the record', () {
expect(holdsExitRecord(_lost, 5059, 5), isFalse);
expect(holdsExitRecord(_lost, 7414, 10), isTrue);
expect(holdsExitRecord(_removed, 5059, 5), isFalse);
});
});

group('removalSettled', () {
test('is false while the previous install records are still listed', () {
expect(
removalSettled(before: _previousInstall, after: _previousInstall),
isFalse,
);
});

test('is false when the records are gone but nothing was persisted', () {
// The records are not what proves the OS is done: the persistence that
// follows the removal is, and it has not happened.
final String gone =
'ACTIVITY MANAGER PROCESS EXIT INFO (dumpsys activity exit-info)\n'
'Last Timestamp of Persistence Into Persistent Storage: '
'1970-01-01 00:00:00.000\n';
expect(removalSettled(before: _previousInstall, after: gone), isFalse);
});

test(
'is false while records are listed even if something was persisted',
() {
// A persistence of some other package's exit does not mean this
// package's removal has been processed.
final String persistedElsewhere = _previousInstall.replaceFirst(
'1970-01-01 00:00:00.000',
'2026-10-08 22:03:56.000',
);
expect(
removalSettled(before: _previousInstall, after: persistedElsewhere),
isFalse,
);
},
);

test('is true once the records are gone and the history was persisted', () {
// The failing run's uninstall at 22:03:55.7, then the removal landing
// and being persisted at 22:04:11.860.
expect(removalSettled(before: _previousInstall, after: _removed), isTrue);
});

test('is true for a passing run, too', () {
final String removedLater = _removed.replaceFirst(
'2026-10-08 22:04:11.860',
'2026-10-08 22:49:32.574',
);
expect(removalSettled(before: _kept, after: removedLater), isTrue);
});

test('waits on the persistence when the old install had no records', () {
// Nothing to see disappear, so only the timestamp can say the removal
// has been processed: unchanged is not settled, moved is.
expect(
removalSettled(before: _emptyBefore, after: _emptyBefore),
isFalse,
);
expect(removalSettled(before: _emptyBefore, after: _removed), isTrue);
});

test('is not settled by the new install\'s own records', () {
// The shape of the failing run: the removal landed after the new
// install had crashed, so the history holds the new uid's records and a
// moved timestamp. Waiting is what keeps the install from being here.
expect(removalSettled(before: _previousInstall, after: _lost), isFalse);
});

test('throws on a dump with no persistence line, rather than guess', () {
expect(
() => removalSettled(before: _previousInstall, after: ''),
throwsFormatException,
);
});
});
}
74 changes: 69 additions & 5 deletions tool/android-crash-harness.dart
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,11 @@
// receiver;
// 5. relaunch once more: nothing may have been recovered.
//
// "Freshly installed" includes the OS having forgotten the previous install:
// uninstalling returns before the activity manager has dropped that install's
// exit records, and dropping them later would take the new install's with them.
// `_Device.reinstall` waits for it, on the OS's own state, before it installs.
//
// A launch is judged once it has been quiet for `--settle` seconds, not when
// the first start-up line appears. Android relaunches an activity in the same
// process, by itself, whenever an asset path or the package's application info
Expand Down Expand Up @@ -60,6 +65,7 @@ import 'dart:async';
import 'dart:convert';
import 'dart:io';

import 'exit-info.dart';
import 'log-window.dart';
import 'otlp-log-sink.dart';

Expand Down Expand Up @@ -369,11 +375,52 @@ class _Device {
}

/// A fresh install, so no earlier run's exit records or watermark survive.
///
/// `adb uninstall` returns when the package manager is done, not the
/// activity manager. The package manager then broadcasts the removal, and
/// when the activity manager's receiver gets it, which on a loaded emulator
/// can be seconds later, it destroys every exit record filed under the
/// package *name*: the new install's too, if it has already crashed. Installed
/// straight away, the next install can crash and have its record filed
/// before that happens, and the harness then reads nothing for a crash that
/// did happen (`received []`). So this dumps the exit history first, and
/// after the uninstall waits until the OS says it has dropped it
/// ([removalSettled]) before it installs, polling every half a second and
/// throwing a [StateError] after two minutes, as it does when `adb` fails.
/// The wait is on the OS's own state and is not a retry: the run itself is
/// untouched and nothing it asserts is relaxed.
///
/// [upgrade] needs none of this. Replacing an install broadcasts a removal
/// marked as a replacement, which the activity manager ignores, so the
/// history is kept: that is the point of an update.
Future<void> reinstall(String apk) async {
const Duration pause = Duration(milliseconds: 500);
const Duration timeout = Duration(seconds: 120);
final String before = await exitInfo();
var uninstalled = false;
try {
await adbCommand(<String>['uninstall', _package]);
uninstalled = true;
} on Object {
// Not installed yet.
// Not installed yet: no removal is coming, so nothing to wait for.
}
if (uninstalled) {
final Stopwatch clock = Stopwatch()..start();
String after = await exitInfo();
while (!removalSettled(before: before, after: after)) {
if (clock.elapsed >= timeout) {
throw StateError(
'the OS still held the previous install\'s exit history '
'${timeout.inSeconds}s after it was uninstalled\n$after',
);
}
await Future<void>.delayed(pause);
after = await exitInfo();
}
stdout.writeln(
' previous install left the exit history after '
'${clock.elapsedMilliseconds} ms',
);
}
await adbCommand(<String>['install', '-r', '-t', apk]);
}
Expand Down Expand Up @@ -517,12 +564,9 @@ class _Device {
int reason, {
Duration timeout = const Duration(seconds: 60),
}) async {
final RegExp record = RegExp(
'pid=$pid\\b(?:(?!ApplicationExitInfo)[\\s\\S])*?reason=$reason \\(',
);
final Stopwatch clock = Stopwatch()..start();
while (clock.elapsed < timeout) {
if (record.hasMatch(await exitInfo())) return true;
if (holdsExitRecord(await exitInfo(), pid, reason)) return true;
await Future<void>.delayed(const Duration(milliseconds: 500));
}
return false;
Expand Down Expand Up @@ -733,6 +777,11 @@ class _KindRun {
'launch 2: expected exactly one "$kind" record, '
'received ${second.kinds}',
);
if (crashing != null && !second.kinds.contains(kind)) {
// Not an assertion of its own: the one above has already failed. It
// says which of the two ways a record goes missing this was.
_problems.add(await _whereTheRecordWent(crashing));
}
final Iterable<SinkRecord> crashes = second.records.where(
(SinkRecord r) => r.crashKind != null,
);
Expand Down Expand Up @@ -814,6 +863,21 @@ class _KindRun {
return false;
}

/// Where the OS's record of [pid]'s death is now that launch 2 reported none:
/// still in its history, so the app lost it, or gone from it, so the OS did.
Future<String> _whereTheRecordWent(int pid) async {
try {
final String dump = await device.exitInfo();
return holdsExitRecord(dump, pid, _exitReason)
? "launch 2: the OS still holds pid $pid's record (the app lost it)"
: "launch 2: the OS removed pid $pid's record "
'(last persisted ${exitInfoPersistedAt(dump)})';
} on Object catch (error) {
return "launch 2: could not read the OS's exit history to say where "
"pid $pid's record went: $error";
}
}

/// The start-up lines of [launch], with the process each came from.
String _lines(_Launch launch) => launch.summaries.isEmpty
? 'no start-up line'
Expand Down
Loading
Loading