feat(mdtest run/auto): support TAP (test anything protocol) test output
format and add --verbose flag for mdtest

mdtest now is able to report test output in TAP format.  If --format
option is set to '--format=tap', mdtest will run
"pub run test --reporter json" to collect test output in json format
and transform json output into tap output on the fly.  The default
behavior is '--format=none' which use the standard dart test output.

mdtest now support --verbose flag.  If -v or --verbose is specified,
printTrace() will direct output to the standard error stream.
Otherwise, printTrace() does nothing.

Replace some print invocation with logging print.

Change-Id: Ie98d7b61393a368ec06e6ad536d2226973e2d322
diff --git a/mdtest/lib/executable.dart b/mdtest/lib/executable.dart
index 46fbe09..7c6f3ba 100644
--- a/mdtest/lib/executable.dart
+++ b/mdtest/lib/executable.dart
@@ -5,11 +5,13 @@
 import 'dart:async';
 import 'dart:io';
 
+import 'package:args/command_runner.dart';
 import 'package:stack_trace/stack_trace.dart';
 
 import 'src/commands/run.dart';
 import 'src/commands/auto.dart';
 import 'src/runner/mdtest_command_runner.dart';
+import 'src/util.dart';
 
 Future<Null> main(List<String> args) async {
   MDTestCommandRunner runner = new MDTestCommandRunner()
@@ -20,6 +22,45 @@
       dynamic result = await runner.run(args);
       exit(result is int ? result : 0);
     }, onError: (dynamic error, Chain chain) {
-      print(error);
+      if (error is UsageException) {
+        stderr.writeln(error.message);
+        stderr.writeln();
+        stderr.writeln(
+          "Run 'mdtest -h' (or 'mdtest <command> -h') for available "
+          "mdtest commands and options."
+        );
+        // Argument error exit code.
+        exit(64);
+      } else {
+        stderr.writeln();
+        stderr.writeln('Oops; mdtest has exit unexpectedly: "${error.toString()}".');
+
+        File crashReport = _createCrashReport(args, error, chain);
+        stderr.writeln(
+          'Crash report written to ${crashReport.path};\n'
+          'please let us know at https://github.com/vanadium/baku/issues.'
+        );
+
+        exit(1);
+      }
     });
 }
+
+File _createCrashReport(List<String> args, dynamic error, Chain chain) {
+  File crashFile = getUniqueFile(Directory.current, 'mdtest', 'log');
+
+  StringBuffer buffer = new StringBuffer();
+
+  buffer.writeln('MDTest crash report; please file at https://github.com/vanadium/baku/issues.\n');
+
+  buffer.writeln('## command\n');
+  buffer.writeln('mdtest ${args.join(' ')}\n');
+
+  buffer.writeln('## exception\n');
+  buffer.writeln('$error\n');
+  buffer.writeln('```\n${chain.terse}```\n');
+
+  crashFile.writeAsStringSync(buffer.toString());
+
+  return crashFile;
+}
diff --git a/mdtest/lib/src/algorithms/matching.dart b/mdtest/lib/src/algorithms/matching.dart
index e75db48..5f97fc8 100644
--- a/mdtest/lib/src/algorithms/matching.dart
+++ b/mdtest/lib/src/algorithms/matching.dart
@@ -138,7 +138,7 @@
 void printMatches(Iterable<Map<DeviceSpec, Device>> matches) {
   StringBuffer sb = new StringBuffer();
   int roundNum = 1;
-  sb.writeln('**********');
+  sb.writeln('=' * 10);
   for (Map<DeviceSpec, Device> match in matches) {
     sb.writeln('Round $roundNum:');
     match.forEach((DeviceSpec spec, Device device) {
@@ -148,6 +148,6 @@
     });
     roundNum++;
   }
-  sb.write('**********');
+  sb.write('=' * 10);
   print(sb.toString());
 }
diff --git a/mdtest/lib/src/base/logger.dart b/mdtest/lib/src/base/logger.dart
index 71bd53b..2c318e1 100644
--- a/mdtest/lib/src/base/logger.dart
+++ b/mdtest/lib/src/base/logger.dart
@@ -7,16 +7,37 @@
 abstract class Logger {
   void info(String message);
   void error(String message);
+  void trace(String message);
 }
 
 class StdoutLogger extends Logger {
   @override
   void info(String message) {
-    stderr.writeln('[info ] $message');
+    stderr.writeln('[INFO] $message');
   }
 
   @override
   void error(String message) {
-    stderr.writeln('[error] $message');
+    stderr.writeln('[ERROR] $message');
+  }
+
+  @override
+  void trace(String message) {}
+}
+
+class VerboseLogger extends Logger {
+  @override
+  void info(String message) {
+    stderr.writeln('[INFO] $message');
+  }
+
+  @override
+  void error(String message) {
+    stderr.writeln('[ERROR] $message');
+  }
+
+  @override
+  void trace(String message) {
+    stderr.writeln('[TRACE] $message');
   }
 }
diff --git a/mdtest/lib/src/commands/auto.dart b/mdtest/lib/src/commands/auto.dart
index 0b01dcf..83dfe9a 100644
--- a/mdtest/lib/src/commands/auto.dart
+++ b/mdtest/lib/src/commands/auto.dart
@@ -30,7 +30,7 @@
 
   @override
   Future<int> runCore() async {
-    print('Running "mdtest auto command" ...');
+    printInfo('Running "mdtest auto command" ...');
 
     this._specs = await loadSpecs(argResults['specs']);
 
@@ -66,6 +66,7 @@
       = <String, CoverageCollector>{};
 
     List<int> errRounds = [];
+    List<int> failRounds = [];
     int roundNum = 1;
     for (Map<DeviceSpec, Device> deviceMapping in chosenMappings) {
       MDTestRunner runner = new MDTestRunner();
@@ -79,15 +80,23 @@
 
       await storeMatches(deviceMapping);
 
-      if (await runner.runAllTests(_specs['test-paths']) != 0) {
-        printError('Tests execution exit with error.');
-        await uninstallTestedApps(deviceMapping);
-        errRounds.add(roundNum++);
-        continue;
+      bool testsFailed;
+      if (argResults['format'] == 'tap') {
+        testsFailed = await runner.runAllTestsToTAP(_specs['test-paths']) != 0;
+      } else {
+        testsFailed = await runner.runAllTests(_specs['test-paths']) != 0;
+      }
+
+      assert(testsFailed != null);
+      if (testsFailed) {
+        printInfo('Some tests in Round #$roundNum failed');
+        failRounds.add(roundNum++);
+      } else {
+        printInfo('All tests in Round #${roundNum++} passed');
       }
 
       if (argResults['coverage']) {
-        print('Collecting code coverage hitmap ...');
+        printTrace('Collecting code coverage hitmap (this may take some time)');
         buildCoverageCollectionTasks(deviceMapping, collectorPool);
         await runCoverageCollectionTasks(collectorPool);
       }
@@ -96,12 +105,18 @@
     }
 
     if (errRounds.isNotEmpty) {
-      printError('Error in Round #${errRounds.join(", #")}');
+      printError('Error in Round #${errRounds.join(', #')}');
       return 1;
     }
 
+    if (failRounds.isNotEmpty) {
+      printInfo('Some tests failed in Round #${failRounds.join(', #')}');
+    } else {
+      printInfo('All tests in all rounds passed');
+    }
+
     if (argResults['coverage']) {
-      print('Computing code coverage for each application ...');
+      printInfo('Computing code coverage for each application ...');
       if (await computeAppsCoverage(collectorPool, name) != 0)
         return 1;
     }
@@ -112,5 +127,6 @@
   AutoCommand() {
     usesSpecsOption();
     usesCoverageFlag();
+    usesTAPReportOption();
   }
 }
diff --git a/mdtest/lib/src/commands/helper.dart b/mdtest/lib/src/commands/helper.dart
index fd7dc55..a954d89 100644
--- a/mdtest/lib/src/commands/helper.dart
+++ b/mdtest/lib/src/commands/helper.dart
@@ -11,6 +11,7 @@
 import '../mobile/device_spec.dart';
 import '../mobile/android.dart';
 import '../test/coverage_collector.dart';
+import '../test/reporter.dart';
 import '../globals.dart';
 import '../util.dart';
 
@@ -74,7 +75,7 @@
     return 0;
   }
 
-  /// Run all tests
+  /// Run all tests without test output reformatting
   Future<int> runAllTests(Iterable<String> testPaths) async {
     int result = 0;
     for (String testPath in testPaths) {
@@ -83,11 +84,26 @@
     return result == 0 ? 0 : 1;
   }
 
-  /// Create a process and invoke 'dart testPath' to run the test script.  After
-  /// test result is returned (either pass or fail), kill all app processes and
-  /// return the current process exit code
+  /// Run all tests with test output in TAP format
+  Future<int> runAllTestsToTAP(Iterable<String> testPaths) async {
+    int result = 0;
+    TAPReporter reporter = new TAPReporter();
+    reporter.printHeader();
+    for (String testPath in testPaths) {
+      result += await runTestToTAP(testPath, reporter);
+    }
+    reporter.printSummary();
+    return result == 0 ? 0 : 1;
+  }
+
+  /// Create a process and invoke 'dart [testPath]' to run the test script.
+  /// After test result is returned (either pass or fail), return the current
+  /// process exit code (0 if success, otherwise failure)
   Future<int> runTest(String testPath) async {
-    Process process = await Process.start('dart', ['$testPath']);
+    Process process = await Process.start(
+      'dart',
+      ['$testPath']
+    );
     RegExp testStopPattern = new RegExp(r'All tests passed|Some tests failed');
     Stream stdoutStream = process.stdout
                                  .transform(new Utf8Decoder())
@@ -101,6 +117,24 @@
     return await process.exitCode;
   }
 
+  /// Create a process and invoke 'pub run test --reporter json [testPath]' to
+  /// run the test script and convert json output into tap output on the fly.
+  /// After test result is returned (either pass or fail), return the current
+  /// process exit code (0 if success, otherwise failure)
+  Future<int> runTestToTAP(String testPath, TAPReporter reporter) async {
+    Process process = await Process.start(
+      'pub',
+      ['run', 'test', '--reporter', 'json', '$testPath']
+    );
+    await reporter.report(
+      process.stdout
+             .transform(new Utf8Decoder())
+             .transform(new LineSplitter())
+    );
+    process.stderr.drain();
+    return await process.exitCode;
+  }
+
   /// Kill all app processes
   Future<Null> killAppProcesses() async {
     for (Process process in appProcesses) {
@@ -151,19 +185,23 @@
     if (coverageData == null)
       return 1;
 
-    String coveragePath = normalizePath(
+    String codeCoverageDirPath = normalizePath(
       appRootPath,
-      '$defaultCodeCoverageDirectoryPath',
-      'cov_${commandName}_${generateTimeStamp()}.info'
+      '$defaultCodeCoverageDirectoryPath'
+    );
+    File codeCoverageReport = getUniqueFile(
+      new Directory(codeCoverageDirPath),
+      'cov_$commandName',
+      'info'
     );
     try {
       // Write coverage info to code_coverage folder
-      new File(coveragePath)
+      codeCoverageReport
         ..createSync(recursive: true)
         ..writeAsStringSync(coverageData, flush: true);
-      print('Writing code coverage to $coveragePath');
+      printTrace('Writing code coverage to ${codeCoverageReport.path}');
     } on FileSystemException {
-      printError('Cannot write code coverage info to $coveragePath');
+      printError('Cannot write code coverage info to ${codeCoverageReport.path}');
       return 1;
     }
   }
diff --git a/mdtest/lib/src/commands/run.dart b/mdtest/lib/src/commands/run.dart
index 45ca296..089ac43 100644
--- a/mdtest/lib/src/commands/run.dart
+++ b/mdtest/lib/src/commands/run.dart
@@ -27,10 +27,10 @@
 
   @override
   Future<int> runCore() async {
-    print('Running "mdtest run command" ...');
+    printInfo('Running "mdtest run command" ...');
 
     this._specs = await loadSpecs(argResults['specs']);
-    print(_specs);
+    printTrace(_specs.toString());
 
     this._devices = await getDevices();
     if (_devices.isEmpty) {
@@ -59,21 +59,31 @@
 
     await storeMatches(deviceMapping);
 
-    if (await runner.runAllTests(_specs['test-paths']) != 0) {
-      printError('Tests execution exit with error.');
-      await uninstallTestedApps(deviceMapping);
-      return 1;
+    bool testsFailed;
+    if (argResults['format'] == 'tap') {
+      testsFailed = await runner.runAllTestsToTAP(_specs['test-paths']) != 0;
+    } else {
+      testsFailed = await runner.runAllTests(_specs['test-paths']) != 0;
+    }
+
+    assert(testsFailed != null);
+    if (testsFailed) {
+      printError('Some tests failed');
+    } else {
+      printInfo('All tests passed');
     }
 
     if (argResults['coverage']) {
       Map<String, CoverageCollector> collectorPool
         = <String, CoverageCollector>{};
       buildCoverageCollectionTasks(deviceMapping, collectorPool);
-      print('Collecting code coverage hitmap ...');
+      printTrace('Collecting code coverage hitmap (this may take some time)');
       await runCoverageCollectionTasks(collectorPool);
-      print('Computing code coverage for each application ...');
-      if (await computeAppsCoverage(collectorPool, name) != 0)
+      printInfo('Computing code coverage for each application ...');
+      if (await computeAppsCoverage(collectorPool, name) != 0) {
+        await uninstallTestedApps(deviceMapping);
         return 1;
+      }
     }
 
     await uninstallTestedApps(deviceMapping);
@@ -84,5 +94,6 @@
   RunCommand() {
     usesSpecsOption();
     usesCoverageFlag();
+    usesTAPReportOption();
   }
 }
diff --git a/mdtest/lib/src/globals.dart b/mdtest/lib/src/globals.dart
index 947bfc0..7ad36ef 100644
--- a/mdtest/lib/src/globals.dart
+++ b/mdtest/lib/src/globals.dart
@@ -4,9 +4,11 @@
 
 import 'base/logger.dart';
 
-final Logger defaultLogger = new StdoutLogger();
+Logger defaultLogger = new StdoutLogger();
 Logger get logger => defaultLogger;
 
 void printInfo(String message) => logger.info(message);
 
 void printError(String message) => logger.error(message);
+
+void printTrace(String message) => logger.trace(message);
diff --git a/mdtest/lib/src/mobile/android.dart b/mdtest/lib/src/mobile/android.dart
index a0072d4..82040dd 100644
--- a/mdtest/lib/src/mobile/android.dart
+++ b/mdtest/lib/src/mobile/android.dart
@@ -90,7 +90,7 @@
                          .transform(new Utf8Decoder())
                          .transform(new LineSplitter());
     await for (var line in lineStream) {
-      print('Uninstall $packageName on device ${device.id}: ${line.toString().trim()}');
+      printTrace('Uninstall $packageName on device ${device.id}: ${line.toString().trim()}');
     }
 
     uninstallProcess.stderr.drain();
diff --git a/mdtest/lib/src/mobile/device_spec.dart b/mdtest/lib/src/mobile/device_spec.dart
index 697daa9..59a18c8 100644
--- a/mdtest/lib/src/mobile/device_spec.dart
+++ b/mdtest/lib/src/mobile/device_spec.dart
@@ -87,7 +87,7 @@
     printError('File $specsPath is not in JSON format.');
     exit(1);
   } catch (e) {
-    print('Unknown Exception details:\n $e');
+    printError('Unknown Exception details:\n $e');
     exit(1);
   }
 }
diff --git a/mdtest/lib/src/runner/mdtest_command.dart b/mdtest/lib/src/runner/mdtest_command.dart
index c20c5e4..3c01a34 100644
--- a/mdtest/lib/src/runner/mdtest_command.dart
+++ b/mdtest/lib/src/runner/mdtest_command.dart
@@ -27,7 +27,6 @@
     argParser.addOption(
       'specs',
       defaultsTo: null,
-      allowMultiple: false,
       help:
         'Path to the config file that specifies the devices, '
         'apps and debug-ports for testing.'
@@ -43,6 +42,14 @@
     );
   }
 
+  void usesTAPReportOption() {
+    argParser.addOption('format',
+      defaultsTo: 'none',
+      allowed: ['none', 'tap'],
+      help: 'Format to be used to display test output result.'
+    );
+  }
+
   @override
   Future<int> run() {
     Stopwatch stopwatch = new Stopwatch()..start();
diff --git a/mdtest/lib/src/runner/mdtest_command_runner.dart b/mdtest/lib/src/runner/mdtest_command_runner.dart
index 81a439a..944ac4c 100644
--- a/mdtest/lib/src/runner/mdtest_command_runner.dart
+++ b/mdtest/lib/src/runner/mdtest_command_runner.dart
@@ -3,13 +3,23 @@
 // license that can be found in the LICENSE file.
 
 import 'dart:async';
+
+import 'package:args/args.dart';
 import 'package:args/command_runner.dart';
 
+import '../base/logger.dart';
+import '../globals.dart';
+
 class MDTestCommandRunner extends CommandRunner {
   MDTestCommandRunner() : super(
     'mdtest',
     'Launch multi-device apps and run test script'
-  );
+  ) {
+    argParser.addFlag('verbose',
+        abbr: 'v',
+        negatable: false,
+        help: 'Noisy logging, including all shell commands executed.');
+  }
 
   @override
   Future<dynamic> run(Iterable<String> args) {
@@ -17,4 +27,11 @@
       return result;
     });
   }
+
+  @override
+  Future<int> runCommand(ArgResults globalResults) async {
+    if (globalResults['verbose'])
+      defaultLogger = new VerboseLogger();
+    return await super.runCommand(globalResults);
+  }
 }
diff --git a/mdtest/lib/src/test/coverage_collector.dart b/mdtest/lib/src/test/coverage_collector.dart
index 4060711..2b6a064 100644
--- a/mdtest/lib/src/test/coverage_collector.dart
+++ b/mdtest/lib/src/test/coverage_collector.dart
@@ -7,6 +7,8 @@
 import 'package:coverage/coverage.dart';
 import 'package:path/path.dart' as path;
 
+import '../globals.dart';
+
 class CoverageCollector {
   List<Future<Null>> _jobs = <Future<Null>>[];
   Map<String, dynamic> _globalHitmap;
@@ -15,8 +17,8 @@
     RegExp urlPattern = new RegExp(r'http://(.*):(\d+)');
     Match urlMatcher = urlPattern.firstMatch(observatoryUrl);
     if (urlMatcher == null) {
-      print('Cannot parse host name and port '
-            'from observatory url $observatoryUrl');
+      printError('Cannot parse host name and port '
+                 'from observatory url $observatoryUrl');
       return;
     }
     String host = urlMatcher.group(1);
diff --git a/mdtest/lib/src/test/reporter.dart b/mdtest/lib/src/test/reporter.dart
new file mode 100644
index 0000000..0a87559
--- /dev/null
+++ b/mdtest/lib/src/test/reporter.dart
@@ -0,0 +1,157 @@
+// Copyright 2016 The Vanadium 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 '../globals.dart';
+
+class TAPReporter {
+  int currentTestNum;
+  int passingTestsNum;
+  Map<int, TestEvent> testEventMapping;
+
+  TAPReporter() {
+    this.currentTestNum = 0;
+    this.passingTestsNum = 0;
+    this.testEventMapping = <int, TestEvent>{};
+  }
+
+  void printHeader() {
+    print(
+      '\n'
+      'TAP version 13'
+    );
+  }
+
+  Future<Null> report(Stream jsonOutput) async {
+    await for (var line in jsonOutput) {
+      convertToTAPFormat(line.toString().trim());
+    }
+    testEventMapping.clear();
+  }
+
+  void printSummary() {
+    print(
+      '\n'
+      '1..$currentTestNum\n'
+      '# tests $currentTestNum\n'
+      '# pass $passingTestsNum\n'
+      '\n'
+    );
+  }
+
+  void convertToTAPFormat(var jsonLine) {
+    if (jsonLine == null)
+      return;
+    dynamic event;
+    try {
+      event = JSON.decode(jsonLine);
+    } on FormatException {
+      printError('File ${jsonLine.toString()} is not in JSON format.');
+      return;
+    }
+
+    if (_isGroupEvent(event) && !_isGroupRootEvent(event)) {
+      dynamic groupInfo = event['group'];
+      bool skip = groupInfo['metadata']['skip'];
+      if (skip) {
+        String skipReason = groupInfo['metadata']['skipReason'] ?? '';
+        print('# skip ${groupInfo['name']} $skipReason');
+      }
+      print('# ${groupInfo['name']}');
+    } else if (_isTestStartEvent(event)) {
+      dynamic testInfo = event['test'];
+      int testID = testInfo['id'];
+      String name = testInfo['name'];
+      bool skip = testInfo['metadata']['skip'];
+      String skipReason = testInfo['metadata']['skipReason'] ?? '';
+      testEventMapping[testID] = new TestEvent(name, skip, skipReason);
+    } else if (_isErrorEvent(event)) {
+      int testID = event['testID'];
+      TestEvent testEvent = testEventMapping[testID];
+      String errorReason = event['error'];
+      testEvent.fillError(errorReason);
+    } else if (_isTestDoneEvent(event)) {
+      int testID = event['testID'];
+      TestEvent testEvent = testEventMapping[testID];
+      testEvent.hidden = event['hidden'];
+      testEvent.result = event['result'];
+      printTestResult(testEvent);
+    }
+  }
+
+  bool _isGroupEvent(dynamic event) {
+    return event['type'] == 'group';
+  }
+
+  bool _isGroupRootEvent(dynamic event) {
+    dynamic groupInfo = event['group'];
+    return _isGroupEvent(event)
+           &&
+           groupInfo['name'] == null
+           &&
+           groupInfo['parentID'] == null;
+  }
+
+  bool _isTestStartEvent(dynamic event) {
+    return event['type'] == 'testStart';
+  }
+
+  bool _isErrorEvent(dynamic event) {
+    return event['type'] == 'error';
+  }
+
+  bool _isTestDoneEvent(dynamic event) {
+    return event['type'] == 'testDone';
+  }
+
+  void printTestResult(TestEvent event) {
+    if (event.hidden)
+      return;
+    if (event.result != 'success') {
+      if (event.error) {
+        print('not ok ${++currentTestNum} - ${event.name}');
+        String tab = '${' ' * 2}';
+        // Print error message
+        event.errorReason.split('\n').forEach((String line) {
+          print('$tab$line');
+        });
+        return;
+      }
+      print('not ok ${++currentTestNum} - ${event.name}');
+      return;
+    }
+    if (event.skip) {
+      print('ok ${++currentTestNum} - # SKIP ${event.skipReason}');
+    }
+    print('ok ${++currentTestNum} - ${event.name}');
+    passingTestsNum++;
+  }
+}
+
+class TestEvent {
+  // Known at TestStartEvent
+  String name;
+  bool skip;
+  String skipReason;
+  // Known at ErrorEvent
+  bool error;
+  String errorReason;
+  // Known at TestDoneEvents
+  String result;
+  bool hidden;
+
+  TestEvent(String name, bool skip, String skipReason) {
+    this.name = name;
+    this.skip = skip;
+    this.skipReason = skipReason;
+    this.error = false;
+  }
+
+  void fillError(String errorReason) {
+    this.error = true;
+    this.errorReason = errorReason;
+  }
+}
diff --git a/mdtest/lib/src/util.dart b/mdtest/lib/src/util.dart
index bf0359c..f195760 100644
--- a/mdtest/lib/src/util.dart
+++ b/mdtest/lib/src/util.dart
@@ -37,12 +37,9 @@
   return minL;
 }
 
-String normalizePath(
-  String rootPath,
-  [String relativePath1, relativePath2]
-) {
+String normalizePath(String rootPath, String relativePath) {
   return path.normalize(
-    path.join(rootPath, relativePath1, relativePath2)
+    path.join(rootPath, relativePath)
   );
 }
 
@@ -61,3 +58,15 @@
   }
   return true;
 }
+
+File getUniqueFile(Directory dir, String baseName, String ext) {
+  int i = 1;
+
+  while (true) {
+    String name = '${baseName}_${i.toString().padLeft(2, '0')}.$ext';
+    File file = new File(path.join(dir.path, name));
+    if (!file.existsSync())
+      return file;
+    i++;
+  }
+}