Improve the log of the updatedb command

src/Commands/core/UpdateDBCommands.php

@@ -179,7 +179,7 @@ public function updateDoOne($module, $number, $dependency_map, &$context)
                     Database::startLog($function);
                 }
 
-                $this->logger()->notice("Executing " . $function);
+                $this->logger()->notice("Update started: $function");
                 $ret['results']['query'] = $function($context['sandbox']);
                 $ret['results']['success'] = true;
             } // @TODO We may want to do different error handling for different exception
@@ -213,14 +213,18 @@ public function updateDoOne($module, $number, $dependency_map, &$context)
         if (!empty($ret['#abort'])) {
             // Record this function in the list of updates that were aborted.
             $context['results']['#abort'][] = $function;
+            // Setting this value will output an error message.
+            // @see \DrushBatchContext::offsetSet()
+            $context['error_message'] = "Update failed: $function";
         }
 
         // Record the schema update if it was completed successfully.
         if ($context['finished'] == 1 && empty($ret['#abort'])) {
             drupal_set_installed_schema_version($module, $number);
+            // Setting this value will output a success message.
+            // @see \DrushBatchContext::offsetSet()
+            $context['message'] = "Update completed: $function";
         }
-
-        $context['message'] = 'Performing ' . $function;
     }
 
     /**
@@ -304,7 +308,10 @@ public function updateBatch($options)
         } elseif (!array_key_exists('object', $result)) {
             $this->logger()->error(dt('Batch process did not return a result object.'));
         } elseif (!empty($result['object'][0]['#abort'])) {
-            $this->logger()->error(dt('Failed batch process: !process', [
+            // Whenever an error occurs the batch process does not continue, so
+            // this array should only contain a single item, but we still output
+            // all available data for completeness.
+            $this->logger()->error(dt('Update aborted by: !process', [
                 '!process' => implode(', ', $result['object'][0]['#abort']),
             ]));
         } else {

tests/CommandUnishTestCase.php

@@ -66,11 +66,39 @@ abstract class CommandUnishTestCase extends UnishTestCase
    */
     protected function getSimplifiedOutput()
     {
-        $output = $this->getOutput();
+        return $this->simplifyOutput($this->getOutput());
+    }
+
+    /**
+     * Returns a simplified version of the error output to facilitate testing.
+     *
+     * @return string
+     *   A simplified version of the error output that has things like full
+     *   paths and superfluous whitespace removed from it.
+     */
+    protected function getSimplifiedErrorOutput()
+    {
+        return $this->simplifyOutput($this->getErrorOutput());
+    }
+
+    /**
+     * Remove things like full paths and extra whitespace from the given string.
+     *
+     * @param string $output
+     *   The output string to simplify.
+     *
+     * @return string
+     *   The simplified output.
+     */
+    protected function simplifyOutput($output)
+    {
         // We do not care if Drush inserts a -t or not in the string. Depends on whether there is a tty.
         $output = preg_replace('# -t #', ' ', $output);
         // Remove double spaces from output to help protect test from false negatives if spacing changes subtlely
         $output = preg_replace('#  *#', ' ', $output);
+        // Remove leading and trailing spaces.
+        $output = preg_replace('#^ *#m', '', $output);
+        $output = preg_replace('# *$#m', '', $output);
         // Debug flags may be added to command strings if we are in debug mode. Take those out so that tests in phpunit --debug mode work
         $output = preg_replace('# --debug #', ' ', $output);
         $output = preg_replace('# --verbose #', ' ', $output);
@@ -479,4 +507,25 @@ protected function assertOutputEquals($expected, $filter = '')
         }
         $this->assertEquals($expected, $output);
     }
+
+    /**
+     * Checks that the error output matches the expected output.
+     *
+     * This matches against a simplified version of the actual output that has
+     * absolute paths and duplicate whitespace removed, to avoid false negatives
+     * on minor differences.
+     *
+     * @param string $expected
+     *   The expected output.
+     * @param string $filter
+     *   Optional regular expression that should be ignored in the error output.
+     */
+    protected function assertErrorOutputEquals($expected, $filter = '')
+    {
+        $output = $this->getSimplifiedErrorOutput();
+        if (!empty($filter)) {
+            $output = preg_replace($filter, '', $output);
+        }
+        $this->assertEquals($expected, $output);
+    }
 }

tests/UpdateDBTest.php

@@ -82,7 +82,20 @@ public function testFailedUpdate()
 
  // Do you wish to run the specified pending updates?: yes.
 LOG;
-        $this->assertOutputEquals(preg_replace('#  *#', ' ', trim($expected_output)));
+        $this->assertOutputEquals(preg_replace('#  *#', ' ', $this->simplifyOutput($expected_output)));
+
+        $expected_error_output = <<<LOG
+ [notice] Update started: woot_update_8101
+ [ok] Update completed: woot_update_8101
+ [notice] Update started: woot_update_8102
+ [error] This is the exception message thrown in woot_update_8102
+ [error] Update failed: woot_update_8102
+ [notice] This is the update message from woot_update_8101
+ [error] Update aborted by: woot_update_8102
+ [error] Finished performing updates.
+LOG;
+
+        $this->assertErrorOutputEquals(preg_replace('#  *#', ' ', $this->simplifyOutput($expected_error_output)));
     }
 
     /**

tests/resources/modules/d8/woot/woot.install

@@ -4,12 +4,12 @@
  * Good update.
  */
 function woot_update_8101() {
-  return t('woot_update_8101');
+  return t('This is the update message from woot_update_8101');
 }
 
 /**
  * Failing update.
  */
 function woot_update_8102() {
-  throw new \Exception('8102 error');
+  throw new \Exception('This is the exception message thrown in woot_update_8102');
 }