flutter/packages/flutter_tools/test/integration.shard/transition_test_utils.dart

// Copyright 2014 The Flutter Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.

import 'dart:async';
import 'dart:convert';
import 'dart:io';

import 'package:meta/meta.dart';
import 'package:process/process.dart';

import '../src/common.dart';
import 'test_utils.dart' show fileSystem;

const ProcessManager processManager = LocalProcessManager();
final String flutterRoot = getFlutterRoot();
final String flutterBin = fileSystem.path.join(flutterRoot, 'bin', 'flutter');

void debugPrint(String message) {
  // This is called to intentionally print debugging output when a test is
  // either taking too long or has failed.
  // ignore: avoid_print
  print(message);
}

typedef LineHandler = String? Function(String line);

abstract class Transition {
  const Transition({this.handler, this.logging});

  /// Callback that is invoked when the transition matches.
  ///
  /// This should not throw, even if the test is failing. (For example, don't use "expect"
  /// in these callbacks.) Throwing here would prevent the [runFlutter] function from running
  /// to completion, which would leave zombie `flutter` processes around.
  final LineHandler? handler;

  /// Whether to enable or disable logging when this transition is matched.
  ///
  /// The default value, null, leaves the logging state unaffected.
  final bool? logging;

  bool matches(String line);

  @protected
  bool lineMatchesPattern(String line, Pattern pattern) {
    if (pattern is String) {
      return line == pattern;
    }
    return line.contains(pattern);
  }

  @protected
  String describe(Pattern pattern) {
    if (pattern is String) {
      return '"$pattern"';
    }
    if (pattern is RegExp) {
      return '/${pattern.pattern}/';
    }
    return '$pattern';
  }
}

class Barrier extends Transition {
  const Barrier(this.pattern, {super.handler, super.logging});
  final Pattern pattern;

  @override
  bool matches(String line) => lineMatchesPattern(line, pattern);

  @override
  String toString() => describe(pattern);
}

class Multiple extends Transition {
  Multiple(
    List<Pattern> patterns, {
    super.handler,
    super.logging,
  })  : _originalPatterns = patterns,
        patterns = patterns.toList();

  final List<Pattern> _originalPatterns;
  final List<Pattern> patterns;

  @override
  bool matches(String line) {
    for (int index = 0; index < patterns.length; index += 1) {
      if (lineMatchesPattern(line, patterns[index])) {
        patterns.removeAt(index);
        break;
      }
    }
    return patterns.isEmpty;
  }

  @override
  String toString() {
    if (patterns.isEmpty) {
      return '${_originalPatterns.map(describe).join(', ')} (all matched)';
    }
    return '${_originalPatterns.map(describe).join(', ')} (matched ${_originalPatterns.length - patterns.length} so far)';
  }
}

class LogLine {
  const LogLine(this.channel, this.stamp, this.message);
  final String channel;
  final String stamp;
  final String message;

  bool get couldBeCrash =>
      message.contains('Oops; flutter has exited unexpectedly:');

  @override
  String toString() => '$stamp $channel: $message';

  void printClearly() {
    debugPrint('$stamp $channel: ${clarify(message)}');
  }

  static String clarify(String line) {
    return line.runes.map<String>((int rune) {
      if (rune >= 0x20 && rune <= 0x7F) {
        return String.fromCharCode(rune);
      }
      switch (rune) {
        case 0x00:
          return '<NUL>';
        case 0x07:
          return '<BEL>';
        case 0x08:
          return '<TAB>';
        case 0x09:
          return '<BS>';
        case 0x0A:
          return '<LF>';
        case 0x0D:
          return '<CR>';
      }
      return '<${rune.toRadixString(16).padLeft(rune <= 0xFF ? 2 : rune <= 0xFFFF ? 4 : 5, '0')}>';
    }).join();
  }
}

class ProcessTestResult {
  const ProcessTestResult(this.exitCode, this.logs);
  final int exitCode;
  final List<LogLine> logs;

  List<String> get stdout {
    return logs
        .where((LogLine log) => log.channel == 'stdout')
        .map<String>((LogLine log) => log.message)
        .toList();
  }

  List<String> get stderr {
    return logs
        .where((LogLine log) => log.channel == 'stderr')
        .map<String>((LogLine log) => log.message)
        .toList();
  }

  @override
  String toString() => 'exit code $exitCode\nlogs:\n  ${logs.join('\n  ')}\n';
}

Future<ProcessTestResult> runFlutter(
  List<String> arguments,
  String workingDirectory,
  List<Transition> transitions, {
  bool debug = false,
  bool logging = true,
  Duration expectedMaxDuration = const Duration(
      minutes:
          10), // must be less than test timeout of 15 minutes! See ../../dart_test.yaml.
}) async {
  final Stopwatch clock = Stopwatch()..start();
  final Process process = await processManager.start(
    <String>[flutterBin, ...arguments],
    workingDirectory: workingDirectory,
  );
  final List<LogLine> logs = <LogLine>[];
  int nextTransition = 0;
  void describeStatus() {
    if (transitions.isNotEmpty) {
      debugPrint('Expected state transitions:');
      for (int index = 0; index < transitions.length; index += 1) {
        debugPrint('${index.toString().padLeft(5)} '
            '${index < nextTransition ? 'ALREADY MATCHED ' : index == nextTransition ? 'NOW WAITING FOR>' : '                '} ${transitions[index]}');
      }
    }
    if (logs.isEmpty) {
      debugPrint(
          'So far nothing has been logged${debug ? "" : "; use debug:true to print all output"}.');
    } else {
      debugPrint(
          'Log${debug ? "" : " (only contains logged lines; use debug:true to print all output)"}:');
      for (final LogLine log in logs) {
        log.printClearly();
      }
    }
  }

  bool streamingLogs = false;
  Timer? timeout;
  void processTimeout() {
    if (!streamingLogs) {
      streamingLogs = true;
      if (!debug) {
        debugPrint(
            'Test is taking a long time (${clock.elapsed.inSeconds} seconds so far).');
      }
      describeStatus();
      debugPrint('(streaming all logs from this point on...)');
    } else {
      debugPrint('(taking a long time...)');
    }
  }

  String stamp() =>
      '[${(clock.elapsed.inMilliseconds / 1000.0).toStringAsFixed(1).padLeft(5)}s]';
  void processStdout(String line) {
    final LogLine log = LogLine('stdout', stamp(), line);
    if (logging) {
      logs.add(log);
    }
    if (streamingLogs) {
      log.printClearly();
    }
    if (nextTransition < transitions.length &&
        transitions[nextTransition].matches(line)) {
      if (streamingLogs) {
        debugPrint('(matched ${transitions[nextTransition]})');
      }
      if (transitions[nextTransition].logging != null) {
        if (!logging && transitions[nextTransition].logging!) {
          logs.add(log);
        }
        logging = transitions[nextTransition].logging!;
        if (streamingLogs) {
          if (logging) {
            debugPrint('(enabled logging)');
          } else {
            debugPrint('(disabled logging)');
          }
        }
      }
      if (transitions[nextTransition].handler != null) {
        final String? command = transitions[nextTransition].handler!(line);
        if (command != null) {
          final LogLine inLog = LogLine('stdin', stamp(), command);
          logs.add(inLog);
          if (streamingLogs) {
            inLog.printClearly();
          }
          process.stdin.write(command);
        }
      }
      nextTransition += 1;
      timeout?.cancel();
      timeout = Timer(expectedMaxDuration ~/ 5,
          processTimeout); // This is not a failure timeout, just when to start logging verbosely to help debugging.
    }
  }

  void processStderr(String line) {
    final LogLine log = LogLine('stdout', stamp(), line);
    logs.add(log);
    if (streamingLogs) {
      log.printClearly();
    }
  }

  if (debug) {
    processTimeout();
  } else {
    timeout = Timer(expectedMaxDuration ~/ 2,
        processTimeout); // This is not a failure timeout, just when to start logging verbosely to help debugging.
  }
  process.stdout
      .transform<String>(utf8.decoder)
      .transform<String>(const LineSplitter())
      .listen(processStdout);
  process.stderr
      .transform<String>(utf8.decoder)
      .transform<String>(const LineSplitter())
      .listen(processStderr);
  unawaited(process.exitCode.timeout(expectedMaxDuration, onTimeout: () {
    // This is a failure timeout, must not be short.
    debugPrint(
        '${stamp()} (process is not quitting, trying to send a "q" just in case that helps)');
    debugPrint('(a functional test should never reach this point)');
    final LogLine inLog = LogLine('stdin', stamp(), 'q');
    logs.add(inLog);
    if (streamingLogs) {
      inLog.printClearly();
    }
    process.stdin.write('q');
    return -1; // discarded
  }).then(
    (int i) => i,
    onError: (Object error) {
      // ignore errors here, they will be reported on the next line
      return -1; // discarded
    },
  ));
  final int exitCode = await process.exitCode;
  if (streamingLogs) {
    debugPrint('${stamp()} (process terminated with exit code $exitCode)');
  }
  timeout?.cancel();
  if (nextTransition < transitions.length) {
    debugPrint(
        'The subprocess terminated before all the expected transitions had been matched.');
    if (logs.any((LogLine line) => line.couldBeCrash)) {
      debugPrint(
          'The subprocess may in fact have crashed. Check the stderr logs below.');
    }
    debugPrint(
        'The transition that we were hoping to see next but that we never saw was:');
    debugPrint(
        '${nextTransition.toString().padLeft(5)} NOW WAITING FOR> ${transitions[nextTransition]}');
    if (!streamingLogs) {
      describeStatus();
      debugPrint('(process terminated with exit code $exitCode)');
    }
    throw TestFailure('Missed some expected transitions.');
  }
  if (streamingLogs) {
    debugPrint('${stamp()} (completed execution successfully!)');
  }
  return ProcessTestResult(exitCode, logs);
}

const int progressMessageWidth = 64;