Add timestamps to various test logging utilities (#9319)

Author: srawlins

packages/devtools_app/integration_test/test_infra/run/_test_app_driver.dart

@@ -346,7 +346,7 @@ abstract class IntegrationTestApp with IOMixin {
 
   Future<int> stop({Future<int>? onTimeout}) async {
     await manuallyStopApp();
-    _debugPrint('Waiting for process to end');
+    _debugPrint('Waiting for app process to end');
     return runProcess!.exitCode.timeout(
       IOMixin.killTimeout,
       onTimeout: () =>

packages/devtools_app/integration_test/test_infra/run/_utils.dart

@@ -6,8 +6,8 @@
 
 bool debugTestScript = false;
 
-void debugLog(String log) {
+void debugLog(String message) {
   if (debugTestScript) {
-    print(log);
+    print('${DateTime.now()}: $message');
   }
 }

packages/devtools_shared/lib/src/test/chrome_driver.dart

@@ -19,8 +19,9 @@ class ChromeDriver with IOMixin {
       const chromedriverExe = 'chromedriver';
       const chromedriverArgs = ['--port=4444'];
       if (debugLogging) {
-        print('starting the chromedriver process');
-        print('> $chromedriverExe ${chromedriverArgs.join(' ')}');
+        print('${DateTime.now()}: starting the chromedriver process');
+        print('${DateTime.now()}: > $chromedriverExe '
+            '${chromedriverArgs.join(' ')}');
       }
       final process = _process = await Process.start(
         chromedriverExe,
@@ -42,7 +43,7 @@ class ChromeDriver with IOMixin {
     await cancelAllStreamSubscriptions();
 
     if (debugLogging) {
-      print('killing the chromedriver process');
+      print('${DateTime.now()}: killing the chromedriver process');
     }
     await killGracefully(process, debugLogging: debugLogging);
   }

packages/devtools_shared/lib/src/test/integration_test_runner.dart

@@ -30,8 +30,8 @@ class IntegrationTestRunner with IOMixin {
     List<String> dartDefineArgs = const <String>[],
     bool debugLogging = false,
   }) async {
-    void debugLog(String log) {
-      if (debugLogging) print(log);
+    void debugLog(String message) {
+      if (debugLogging) print('${DateTime.now()}: $message');
     }
 
     Future<void> runTest({required int attemptNumber}) async {
@@ -146,7 +146,9 @@ class IntegrationTestRunner with IOMixin {
               'Integration test timed out on try #$attemptNumber. Retrying '
               '$testTarget now.',
             );
-            await runTest(attemptNumber: ++attemptNumber);
+            attemptNumber++;
+            debugLog('running the test (attempt $attemptNumber)');
+            await runTest(attemptNumber: attemptNumber);
           }
         }
 
@@ -156,6 +158,7 @@ class IntegrationTestRunner with IOMixin {
       }
     }
 
+    debugLog('running the test (attempt 1)');
     await runTest(attemptNumber: 0);
   }
 }
@@ -300,8 +303,8 @@ Future<void> runOneOrManyTests<T extends IntegrationTestRunnerArgs>({
     return;
   }
 
-  void debugLog(String log) {
-    if (debugLogging) print(log);
+  void debugLog(String message) {
+    if (debugLogging) print('${DateTime.now()}: $message');
   }
 
   final chromedriver = ChromeDriver();

packages/devtools_shared/lib/src/test/io_utils.dart

@@ -83,30 +83,30 @@ mixin IOMixin {
     final processId = process.pid;
     if (debugLogging) {
       print(
-        'Cancelling all stream subscriptions for process $processId before '
-        'killing.',
+        '${DateTime.now()}: Cancelling all stream subscriptions for process '
+        '$processId before killing.',
       );
     }
     await cancelAllStreamSubscriptions();
     if (debugLogging) {
-      print('Sending SIGTERM to $processId.');
+      print('${DateTime.now()}: Sending SIGTERM to $processId.');
     }
     Process.killPid(processId);
     return process.exitCode.timeout(
       killTimeout,
-      onTimeout: () => killForcefully(process, debugLogging: debugLogging),
+      onTimeout: () => _killForcefully(process, debugLogging: debugLogging),
     );
   }
 
-  Future<int> killForcefully(
+  Future<int> _killForcefully(
     Process process, {
     bool debugLogging = false,
   }) {
     final processId = process.pid;
     // Use sigint here instead of sigkill. See
     // https://github.com/flutter/flutter/issues/117415.
     if (debugLogging) {
-      print('Sending SIGINT to $processId.');
+      print('${DateTime.now()}: Sending SIGINT to $processId.');
     }
     Process.killPid(processId, ProcessSignal.sigint);
     return process.exitCode;

packages/devtools_test/lib/src/helpers/utils.dart

@@ -240,7 +240,7 @@ Future<Finder> retryUntilFound(
   return retryUntilFound(finder, tester: tester, retries: retries - 1);
 }
 
-void logStatus(String log) {
+void logStatus(String message) {
   // ignore: avoid_print, intentional print for test output
-  print('TEST STATUS: $log');
+  print('${DateTime.now()}: TEST STATUS: $message');
 }