Improve, test, and fix a bug related to adb logcat filtering.

testing/run_tests.py

@@ -909,6 +909,7 @@ def build_dart_host_test_list(build_dir):
       ),
       (os.path.join('flutter', 'testing', 'litetest'), []),
       (os.path.join('flutter', 'testing', 'skia_gold_client'), []),
+      (os.path.join('flutter', 'testing', 'scenario_app'), []),
       (
           os.path.join('flutter', 'tools', 'api_check'),
           [os.path.join(BUILDROOT_DIR, 'flutter')],

testing/scenario_app/bin/utils/adb_logcat_filtering.dart

@@ -30,6 +30,8 @@
 /// See also: <https://developer.android.com/tools/logcat>.
 library;
 
+import 'package:meta/meta.dart';
+
 import 'logs.dart';
 
 /// Represents a line of `adb logcat` output parsed into a structured form.
@@ -74,6 +76,26 @@ extension type const AdbLogLine._(Match _match) {
     return null;
   }
 
+  @visibleForTesting
+  static const Set<String> kKnownNoiseTags = <String>{
+    'MonitoringInstr',
+    'ResourceExtractor',
+    'THREAD_STATE',
+    'ziparchive',
+  };
+
+  @visibleForTesting
+  static const Set<String> kKnownUsefulGeneralTags = <String>{
+    'utter.scenario',
+    'utter.scenarios',
+    'TestRunner',
+  };
+
+  @visibleForTesting
+  static const Set<String> kKnownUsefulErrorTags = <String>{
+    'androidemu',
+  };
+
   /// Returns `true` if the log line is verbose.
   bool isVerbose({String? filterProcessId}) => !_isRelevant(filterProcessId: filterProcessId);
   bool _isRelevant({String? filterProcessId}) {
@@ -87,32 +109,26 @@ extension type const AdbLogLine._(Match _match) {
       return false;
     }
 
-    // These are "known" noise tags.
-    if (const <String>{
-      'MonitoringInstr',
-      'ResourceExtractor',
-      'THREAD_STATE',
-      'ziparchive',
-    }.contains(name)) {
+    if (kKnownNoiseTags.contains(name)) {
       return false;
     }
 
-    // These are "known" tags useful for debugging.
-    if (const <String>{
-      'utter.scenario',
-      'utter.scenarios',
-      'TestRunner',
-    }.contains(name)) {
+    if (kKnownUsefulGeneralTags.contains(name)) {
       return true;
     }
 
-    // If a process ID is specified, exclude logs _not_ from that process.
-    if (filterProcessId != null && process != filterProcessId) {
-      return false;
+    if (severity == 'E' && kKnownUsefulErrorTags.contains(name)) {
+      return true;
     }
 
-    // And... whatever, include anything with the word "flutter".
-    return name.toLowerCase().contains('flutter') || message.toLowerCase().contains('flutter');
+    // If a process ID is specified, exclude logs _not_ from that process.
+    if (filterProcessId == null) {
+      // YOLO, let's keep it anyway.
+      return name.toLowerCase().contains('flutter') ||
+          message.toLowerCase().contains('flutter');
+    } else {
+      return process == filterProcessId;
+    }
   }
 
   /// Logs the line to the console.

testing/scenario_app/pubspec.yaml

@@ -25,9 +25,14 @@ dependencies:
   vector_math: any
   skia_gold_client: any
 
+dev_dependencies:
+  litetest: any
+
 dependency_overrides:
   args:
     path: ../../../third_party/dart/third_party/pkg/args
+  async_helper:
+    path: ../../../third_party/dart/pkg/async_helper
   collection:
     path: ../../../third_party/dart/third_party/pkg/collection
   crypto:
@@ -36,8 +41,12 @@ dependency_overrides:
     path: ../../tools/dir_contents_diff
   engine_repo_tools:
     path: ../../tools/pkg/engine_repo_tools
+  expect:
+    path: ../../../third_party/dart/pkg/expect
   file:
     path: ../../../third_party/dart/third_party/pkg/file/packages/file
+  litetest:
+    path: ../litetest
   meta:
     path: ../../../third_party/dart/pkg/meta
   path:
@@ -48,6 +57,8 @@ dependency_overrides:
     path: ../../third_party/pkg/process
   skia_gold_client:
     path: ../../testing/skia_gold_client
+  smith:
+    path: ../../../third_party/dart/pkg/smith
   sky_engine:
     path: ../../sky/packages/sky_engine
   typed_data:

testing/scenario_app/test/adb_log_filter_test.dart

@@ -0,0 +1,94 @@
+import 'package:litetest/litetest.dart';
+
+import '../bin/utils/adb_logcat_filtering.dart';
+import 'src/fake_adb_logcat.dart';
+
+void main() {
+  /// Simulates the filtering of logcat output [lines].
+  Iterable<String> filter(Iterable<String> lines, {int? filterProcessId}) {
+    if (lines.isEmpty) {
+      throw StateError('No log lines to filter. This is unexpected.');
+    }
+    return lines.where((String line) {
+      final AdbLogLine? logLine = AdbLogLine.tryParse(line);
+      if (logLine == null) {
+        throw StateError('Invalid log line: $line');
+      }
+      final bool isVerbose = logLine.isVerbose(filterProcessId: filterProcessId?.toString());
+      return !isVerbose;
+    });
+  }
+
+  test('should always retain fatal logs', () {
+    final FakeAdbLogcat logcat = FakeAdbLogcat();
+    final FakeAdbProcess process = logcat.withProcess();
+    process.fatal('Something', 'A bad thing happened');
+
+    final Iterable<String> filtered = filter(logcat.drain());
+    expect(filtered, hasLength(1));
+    expect(filtered.first, contains('Something: A bad thing happened'));
+  });
+
+  test('should never retain debug logs', () {
+    final FakeAdbLogcat logcat = FakeAdbLogcat();
+    final FakeAdbProcess process = logcat.withProcess();
+    final String tag = AdbLogLine.kKnownNoiseTags.first;
+    process.debug(tag, 'A debug message');
+
+    final Iterable<String> filtered = filter(logcat.drain());
+    expect(filtered, isEmpty);
+  });
+
+  test('should never retain logs from known "noise" tags', () {
+    final FakeAdbLogcat logcat = FakeAdbLogcat();
+    final FakeAdbProcess process = logcat.withProcess();
+    final String tag = AdbLogLine.kKnownNoiseTags.first;
+    process.info(tag, 'Flutter flutter flutter');
+
+    final Iterable<String> filtered = filter(logcat.drain());
+    expect(filtered, isEmpty);
+  });
+
+  test('should always retain logs from known "useful" tags', () {
+    final FakeAdbLogcat logcat = FakeAdbLogcat();
+    final FakeAdbProcess process = logcat.withProcess();
+    final String tag = AdbLogLine.kKnownUsefulGeneralTags.first;
+    process.info(tag, 'A useful message');
+
+    final Iterable<String> filtered = filter(logcat.drain());
+    expect(filtered, hasLength(1));
+    expect(filtered.first, contains('$tag: A useful message'));
+  });
+
+  test('if a process ID is passed, retain the log', () {
+    final FakeAdbLogcat logcat = FakeAdbLogcat();
+    final FakeAdbProcess process = logcat.withProcess();
+    process.info('SomeTag', 'A message');
+
+    final Iterable<String> filtered = filter(logcat.drain(), filterProcessId: process.processId);
+    expect(filtered, hasLength(1));
+    expect(filtered.first, contains('SomeTag: A message'));
+  });
+
+  test('even if a process ID passed, retain logs containing "flutter"', () {
+    final FakeAdbLogcat logcat = FakeAdbLogcat();
+    final FakeAdbProcess process = logcat.withProcess();
+    process.info('SomeTag', 'A message with flutter');
+
+    final Iterable<String> filtered = filter(logcat.drain(), filterProcessId: process.processId);
+    expect(filtered, hasLength(1));
+    expect(filtered.first, contains('SomeTag: A message with flutter'));
+  });
+
+  test('should retain E-level flags from known "useful" error tags', () {
+    final FakeAdbLogcat logcat = FakeAdbLogcat();
+    final FakeAdbProcess process = logcat.withProcess();
+    final String tag = AdbLogLine.kKnownUsefulErrorTags.first;
+    process.error(tag, 'An error message');
+    process.info(tag, 'An info message');
+
+    final Iterable<String> filtered = filter(logcat.drain());
+    expect(filtered, hasLength(1));
+    expect(filtered.first, contains('$tag: An error message'));
+  });
+}

testing/scenario_app/test/src/fake_adb_logcat.dart

@@ -0,0 +1,145 @@
+import '../../bin/utils/adb_logcat_filtering.dart';
+
+/// Simulates the output of `adb logcat`, i.e. for testing.
+///
+/// ## Example
+///
+/// ```dart
+/// final FakeAdbLogcat logcat = FakeAdbLogcat();
+/// final FakeAdbProcess process = logcat.withProcess();
+/// process.info('ActivityManager', 'Force stopping dev.flutter.scenarios appid=10226 user=0: start instr');
+/// // ...
+/// final List<String> logLines = logcat.drain();
+/// // ...
+/// ```
+final class FakeAdbLogcat {
+  final List<String> _lines = <String>[];
+  final Map<int, FakeAdbProcess> _processById = <int, FakeAdbProcess>{};
+
+  /// The current date and time.
+  DateTime _now = DateTime.now();
+
+  /// Returns the date and time for the next log line.
+  ///
+  /// Time is progressed by 1 second each time this method is called.
+  DateTime _progressTime({Duration by = const Duration(seconds: 1)}) {
+    _now = _now.add(by);
+    return _now;
+  }
+
+  /// `02-22 13:54:39.839`
+  static String _formatTime(DateTime time) {
+    return '${time.month.toString().padLeft(2, '0')}-'
+        '${time.day.toString().padLeft(2, '0')} '
+        '${time.hour.toString().padLeft(2, '0')}:'
+        '${time.minute.toString().padLeft(2, '0')}:'
+        '${time.second.toString().padLeft(2, '0')}.'
+        '${time.millisecond.toString().padLeft(3, '0')}';
+  }
+
+  void _write({
+    required int processId,
+    required int threadId,
+    required String severity,
+    required String tag,
+    required String message,
+  }) {
+    final DateTime time = _progressTime();
+    final String line = '${_formatTime(time)}   $processId  $threadId $severity $tag: $message';
+    assert(AdbLogLine.tryParse(line) != null, 'Invalid log line: $line');
+    _lines.add(line);
+  }
+
+  /// Drains the stored log lines and returns them.
+  List<String> drain() {
+    final List<String> result = List<String>.from(_lines);
+    _lines.clear();
+    return result;
+  }
+
+  /// Creates a new process writing to this logcat.
+  ///
+  /// Optionally specify a [processId] to use for the process, otherwise a
+  /// simple default is used (sequential numbers starting from 1000).
+  FakeAdbProcess withProcess({int? processId}) {
+    processId ??= 1000 + _processById.length;
+    return _processById.putIfAbsent(
+      processId,
+      () => _createProcess(processId: processId!),
+    );
+  }
+
+  FakeAdbProcess _createProcess({required int processId}) {
+    return FakeAdbProcess._(this, processId: processId);
+  }
+}
+
+/// A stateful fixture that represents a fake process writing to `adb logcat`.
+///
+/// See [FakeAdbLogcat.withProcess] for how to create this fixture.
+final class FakeAdbProcess {
+  const FakeAdbProcess._(
+    this._logcat, {
+    required this.processId,
+  });
+
+  final FakeAdbLogcat _logcat;
+
+  /// The process ID of this process.
+  final int processId;
+
+  /// Writes a debug log message.
+  void debug(String tag, String message, {int threadId = 1}) {
+    _logcat._write(
+      processId: processId,
+      threadId: threadId,
+      severity: 'D',
+      tag: tag,
+      message: message,
+    );
+  }
+
+  /// Writes an info log message.
+  void info(String tag, String message, {int threadId = 1}) {
+    _logcat._write(
+      processId: processId,
+      threadId: threadId,
+      severity: 'I',
+      tag: tag,
+      message: message,
+    );
+  }
+
+  /// Writes a warning log message.
+  void warning(String tag, String message, {int threadId = 1}) {
+    _logcat._write(
+      processId: processId,
+      threadId: threadId,
+      severity: 'W',
+      tag: tag,
+      message: message,
+    );
+  }
+
+  /// Writes an error log message.
+  void error(String tag, String message, {int threadId = 1}) {
+    _logcat._write(
+      processId: processId,
+      threadId: threadId,
+      severity: 'E',
+      tag: tag,
+      message: message,
+    );
+  }
+
+  /// Writes a fatal log message.
+  void fatal(String tag, String message, {int threadId = 1}) {
+    _logcat._write(
+      processId: processId,
+      threadId: threadId,
+      severity: 'F',
+      tag: tag,
+      message: message,
+    );
+  }
+}