Issue #3259814 by phenaproxima, kunal.sachdev, tedbow: If a Cron update fails...

Issue #3259814 by phenaproxima, kunal.sachdev, tedbow: If a Cron update fails after it has started the stage should be destroyed

src/CronUpdater.php

@@ -107,30 +107,46 @@ class CronUpdater extends Updater {
     // @todo Use the queue to add update jobs allowing jobs to span multiple
     //   cron runs.
     $recommended_version = $recommended_release->getVersion();
+
+    // Do the bulk of the update in its own try-catch structure, so that we can
+    // handle any exceptions or validation errors consistently, and destroy the
+    // stage regardless of whether the update succeeds.
     try {
       $this->begin([
         'drupal' => $recommended_version,
       ]);
       $this->stage();
       $this->apply();
-      $this->destroy();
-    }
-    catch (StageValidationException $e) {
-      $this->logger->error(static::formatValidationException($e));
-      return;
+
+      $this->logger->info(
+        'Drupal core has been updated from %previous_version to %update_version',
+        [
+          '%previous_version' => $project['existing_version'],
+          '%update_version' => $recommended_version,
+        ]
+      );
     }
     catch (\Throwable $e) {
-      $this->logger->error($e->getMessage());
+      $this->handleException($e);
+    }
+
+    // If an error occurred during the pre-create event, the stage will be
+    // marked as available and we shouldn't try to destroy it, since the stage
+    // must be claimed in order to be destroyed.
+    if ($this->isAvailable()) {
       return;
     }
 
-    $this->logger->info(
-      'Drupal core has been updated from %previous_version to %update_version',
-      [
-        '%previous_version' => $project['existing_version'],
-        '%update_version' => $recommended_version,
-      ]
-    );
+    // If any pre-destroy event subscribers raise validation errors, ensure they
+    // are formatted and logged. But if any pre- or post-destroy event
+    // subscribers throw another exception, don't bother catching it, since it
+    // will be caught and handled by the main cron service.
+    try {
+      $this->destroy();
+    }
+    catch (StageValidationException $e) {
+      $this->handleException($e);
+    }
   }
 
   /**
@@ -160,4 +176,17 @@ class CronUpdater extends Updater {
     return "<h2>{$exception->getMessage()}</h2>$log_message";
   }
 
+  /**
+   * Handles an exception that is caught during an update.
+   *
+   * @param \Throwable $e
+   *   The caught exception.
+   */
+  protected function handleException(\Throwable $e): void {
+    $message = $e instanceof StageValidationException
+      ? static::formatValidationException($e)
+      : $e->getMessage();
+    $this->logger->error($message);
+  }
+
 }

tests/src/Kernel/CronUpdaterTest.php

@@ -6,7 +6,15 @@ use Drupal\automatic_updates\CronUpdater;
 use Drupal\automatic_updates_test\ReadinessChecker\TestChecker1;
 use Drupal\Core\Form\FormState;
 use Drupal\Core\Logger\RfcLogLevel;
+use Drupal\package_manager\Event\PostApplyEvent;
+use Drupal\package_manager\Event\PostCreateEvent;
+use Drupal\package_manager\Event\PostDestroyEvent;
+use Drupal\package_manager\Event\PostRequireEvent;
+use Drupal\package_manager\Event\PreApplyEvent;
+use Drupal\package_manager\Event\PreDestroyEvent;
+use Drupal\package_manager\Event\PreRequireEvent;
 use Drupal\package_manager\Event\PreCreateEvent;
+use Drupal\package_manager\Exception\StageValidationException;
 use Drupal\package_manager\ValidationResult;
 use Drupal\Tests\package_manager\Traits\PackageManagerBypassTestTrait;
 use Drupal\update\UpdateSettingsForm;
@@ -31,6 +39,30 @@ class CronUpdaterTest extends AutomaticUpdatesKernelTestBase {
     'automatic_updates_test',
   ];
 
+  /**
+   * The test logger.
+   *
+   * @var \Psr\Log\Test\TestLogger
+   */
+  private $logger;
+
+  /**
+   * {@inheritdoc}
+   */
+  protected function setUp(): void {
+    // Because package_manager_bypass is enabled, a staging directory will not
+    // actually exist. Therefore, we need to disable these validators because
+    // they attempt to compare the active and stage directories.
+    $this->disableValidators[] = 'automatic_updates.validator.staged_database_updates';
+    $this->disableValidators[] = 'automatic_updates.staged_projects_validator';
+    parent::setUp();
+
+    $this->logger = new TestLogger();
+    $this->container->get('logger.factory')
+      ->get('automatic_updates')
+      ->addLogger($this->logger);
+  }
+
   /**
    * Data provider for ::testUpdaterCalled().
    *
@@ -125,6 +157,68 @@ class CronUpdaterTest extends AutomaticUpdatesKernelTestBase {
     $this->assertCount($will_update, $this->container->get('package_manager.committer')->getInvocationArguments());
   }
 
+  /**
+   * Data provider for ::testStageDestroyedOnError().
+   *
+   * @return array[]
+   *   Sets of arguments to pass to the test method.
+   */
+  public function providerStageDestroyedOnError(): array {
+    return [
+      'pre-create exception' => [
+        PreCreateEvent::class,
+        'Exception',
+      ],
+      'post-create exception' => [
+        PostCreateEvent::class,
+        'Exception',
+      ],
+      'pre-require exception' => [
+        PreRequireEvent::class,
+        'Exception',
+      ],
+      'post-require exception' => [
+        PostRequireEvent::class,
+        'Exception',
+      ],
+      'pre-apply exception' => [
+        PreApplyEvent::class,
+        'Exception',
+      ],
+      'post-apply exception' => [
+        PostApplyEvent::class,
+        'Exception',
+      ],
+      'pre-destroy exception' => [
+        PreDestroyEvent::class,
+        'Exception',
+      ],
+      'post-destroy exception' => [
+        PostDestroyEvent::class,
+        'Exception',
+      ],
+      // Only pre-operation events can add validation results.
+      // @see \Drupal\package_manager\Event\PreOperationStageEvent
+      // @see \Drupal\package_manager\Stage::dispatch()
+      'pre-create validation error' => [
+        PreCreateEvent::class,
+        StageValidationException::class,
+      ],
+      'pre-require validation error' => [
+        PreRequireEvent::class,
+        StageValidationException::class,
+      ],
+      'pre-apply validation error' => [
+        PreApplyEvent::class,
+        StageValidationException::class,
+      ],
+      'pre-destroy validation error' => [
+        PreDestroyEvent::class,
+        StageValidationException::class,
+      ],
+    ];
+  }
+
   /**
    * Data provider for testErrors().
    *
@@ -165,6 +259,100 @@ class CronUpdaterTest extends AutomaticUpdatesKernelTestBase {
     ];
   }
 
+  /**
+   * Tests that the stage is destroyed if an error occurs during a cron update.
+   *
+   * @param string $event_class
+   *   The stage life cycle event which should raise an error.
+   * @param string $exception_class
+   *   The class of exception that will be thrown when the given event is fired.
+   *
+   * @dataProvider providerStageDestroyedOnError
+   */
+  public function testStageDestroyedOnError(string $event_class, string $exception_class): void {
+    $this->installConfig('automatic_updates');
+    $this->setCoreVersion('9.8.0');
+    // Ensure that there is a security release to which we should update.
+    $this->setReleaseMetadata(__DIR__ . "/../../fixtures/release-history/drupal.9.8.1-security.xml");
+
+    // If the pre- or post-destroy events throw an exception, it will not be
+    // caught by the cron updater, but it *will* be caught by the main cron
+    // service, which will log it as a cron error that we'll want to check for.
+    $cron_logger = new TestLogger();
+    $this->container->get('logger.factory')
+      ->get('cron')
+      ->addLogger($cron_logger);
+
+    // When the event specified by $event_class is fired, either throw an
+    // exception directly from the event subscriber, or set a validation error
+    // (if the exception class is StageValidationException).
+    if ($exception_class === StageValidationException::class) {
+      $results = [
+        ValidationResult::createError(['Destroy the stage!']),
+      ];
+      TestChecker1::setTestResult($results, $event_class);
+      $exception = new StageValidationException($results, 'Unable to complete the update because of errors.');
+      $expected_log_message = TestCronUpdater::formatValidationException($exception);
+    }
+    else {
+      /** @var \Throwable $exception */
+      $exception = new $exception_class('Destroy the stage!');
+      TestChecker1::setException($exception, $event_class);
+      $expected_log_message = $exception->getMessage();
+    }
+    // Ensure that nothing has been logged yet.
+    $this->assertEmpty($cron_logger->records);
+    $this->assertEmpty($this->logger->records);
+
+    /** @var \Drupal\automatic_updates\CronUpdater $updater */
+    $updater = $this->container->get('automatic_updates.cron_updater');
+    $this->assertTrue($updater->isAvailable());
+    $this->container->get('cron')->run();
+
+    $logged_by_updater = $this->logger->hasRecord($expected_log_message, RfcLogLevel::ERROR);
+    // To check if the exception was logged by the main cron service, we need
+    // to set up a special predicate, because exceptions logged by cron are
+    // always formatted in a particular way that we don't control. But the
+    // original exception object is stored with the log entry, so we look for
+    // that and confirm that its message is the same.
+    // @see watchdog_exception()
+    $predicate = function (array $record) use ($exception): bool {
+      if (isset($record['context']['exception'])) {
+        return $record['context']['exception']->getMessage() === $exception->getMessage();
+      }
+      return FALSE;
+    };
+    $logged_by_cron = $cron_logger->hasRecordThatPasses($predicate, RfcLogLevel::ERROR);
+
+    // If a pre-destroy event flags a validation error, it's handled like any
+    // other event (logged by the cron updater, but not the main cron service).
+    // But if a pre- or post-destroy event throws an exception, the cron updater
+    // won't try to catch it. Instead, it will be caught and logged by the main
+    // cron service.
+    if ($event_class === PreDestroyEvent::class || $event_class === PostDestroyEvent::class) {
+      if ($exception instanceof StageValidationException) {
+        $this->assertTrue($logged_by_updater);
+        $this->assertFalse($logged_by_cron);
+      }
+      else {
+        $this->assertFalse($logged_by_updater);
+        $this->assertTrue($logged_by_cron);
+      }
+      // If the pre-destroy event throws an exception or flags a validation
+      // error, the stage won't be destroyed. But, once the post-destroy event
+      // is fired, the stage should be fully destroyed and marked as available.
+      $this->assertSame($event_class === PostDestroyEvent::class, $updater->isAvailable());
+    }
+    // For all other events, the error should be caught and logged by the cron
+    // updater, not the main cron service, and the stage should always be
+    // destroyed and marked as available.
+    else {
+      $this->assertTrue($logged_by_updater);
+      $this->assertFalse($logged_by_cron);
+      $this->assertTrue($updater->isAvailable());
+    }
+  }
+
   /**
    * Tests errors during a cron update attempt.
    *
@@ -177,15 +365,9 @@ class CronUpdaterTest extends AutomaticUpdatesKernelTestBase {
    */
   public function testErrors(array $validation_results, string $expected_log_message): void {
     TestChecker1::setTestResult($validation_results, PreCreateEvent::class);
-
-    $logger = new TestLogger();
-    $this->container->get('logger.factory')
-      ->get('automatic_updates')
-      ->addLogger($logger);
-
     $this->container->get('cron')->run();
     $this->assertUpdateStagedTimes(0);
-    $this->assertTrue($logger->hasRecord("<h2>Unable to complete the update because of errors.</h2>$expected_log_message", RfcLogLevel::ERROR));
+    $this->assertTrue($this->logger->hasRecord("<h2>Unable to complete the update because of errors.</h2>$expected_log_message", RfcLogLevel::ERROR));
   }
 
 }