Issue #3355628 by kunal.sachdev, phenaproxima, Wim Leers, tedbow, omkar.podey,...

Issue #3355628 by kunal.sachdev, phenaproxima, Wim Leers, tedbow, omkar.podey, wendyZ: Package Manager should keep an audit log of changes it applied to the active codebase

automatic_updates_extensions/tests/src/Build/ModuleUpdateTest.php

@@ -94,6 +94,8 @@ END;
 
     $module_composer_json = json_decode($file_contents['web/modules/contrib/alpha/composer.json']);
     $this->assertSame('1.1.0', $module_composer_json?->version);
+    $this->assertRequestedChangesWereLogged(['Update drupal/alpha from 1.0.0 to 1.1.0']);
+    $this->assertAppliedChangesWereLogged(['Updated drupal/alpha from 1.0.0 to 1.1.0']);
   }
 
   /**
@@ -131,6 +133,8 @@ END;
     $this->waitForBatchJob();
     $assert_session->pageTextContains('Update complete!');
     $this->assertModuleVersion('alpha', '1.1.0');
+    $this->assertRequestedChangesWereLogged(['Update drupal/alpha from 1.0.0 to 1.1.0']);
+    $this->assertAppliedChangesWereLogged(['Updated drupal/alpha from 1.0.0 to 1.1.0']);
   }
 
   /**

package_manager/package_manager.services.yml

@@ -26,6 +26,10 @@ services:
     parent: logger.channel_base
     arguments:
       - 'package_manager'
+  logger.channel.package_manager_change_log:
+    parent: logger.channel_base
+    arguments:
+      - 'package_manager_change_log'
 
   # Services provided to Drupal by Package Manager.
   package_manager.beginner:
@@ -53,6 +57,11 @@ services:
     autowire: false
     tags:
       - { name: event_subscriber }
+  Drupal\package_manager\EventSubscriber\ChangeLogger:
+    calls:
+      - [setLogger, ['@logger.channel.package_manager_change_log']]
+    tags:
+      - { name: event_subscriber }
   package_manager.composer_inspector:
     class: Drupal\package_manager\ComposerInspector
     calls:

package_manager/src/EventSubscriber/ChangeLogger.php

+<?php
+
+declare(strict_types = 1);
+
+namespace Drupal\package_manager\EventSubscriber;
+
+use Drupal\Core\StringTranslation\StringTranslationTrait;
+use Drupal\package_manager\Event\PostApplyEvent;
+use Drupal\package_manager\Event\PostRequireEvent;
+use Drupal\package_manager\ComposerInspector;
+use Drupal\package_manager\Event\PreCreateEvent;
+use Drupal\package_manager\PathLocator;
+use Psr\Log\LoggerAwareInterface;
+use Psr\Log\LoggerAwareTrait;
+use Symfony\Component\EventDispatcher\EventSubscriberInterface;
+
+/**
+ * Event subscriber to log changes that happen during the stage life cycle.
+ *
+ * @internal
+ *   This is an internal part of Package Manager and may be changed or removed
+ *   at any time without warning. External code should not interact with this
+ *   class.
+ */
+final class ChangeLogger implements EventSubscriberInterface, LoggerAwareInterface {
+
+  use LoggerAwareTrait;
+  use StringTranslationTrait;
+
+  /**
+   * The metadata key under which to store the installed packages at start.
+   *
+   * @var string
+   *
+   * @see ::recordInstalledPackages()
+   */
+  private const INSTALLED_PACKAGES_KEY = 'package_manager_installed_packages';
+
+  /**
+   * The metadata key under which to store the requested package versions.
+   *
+   * @var string
+   *
+   * @see ::recordRequestedPackageVersions()
+   */
+  private const REQUESTED_PACKAGES_KEY = 'package_manager_requested_packages';
+
+  /**
+   * Constructs a ChangeLogger object.
+   *
+   * @param \Drupal\package_manager\ComposerInspector $composerInspector
+   *   The Composer inspector service.
+   * @param \Drupal\package_manager\PathLocator $pathLocator
+   *   The path locator service.
+   */
+  public function __construct(
+    private readonly ComposerInspector $composerInspector,
+    private readonly PathLocator $pathLocator,
+  ) {}
+
+  /**
+   * Records packages installed in the project root.
+   *
+   * We need to do this before the stage has been created, so that we have a
+   * complete picture of which requested packages are merely being updated, and
+   * which are being newly added. Once the stage has been created, the installed
+   * packages won't change -- if they do, a validation error will be raised.
+   *
+   * @param \Drupal\package_manager\Event\PreCreateEvent $event
+   *   The event being handled.
+   *
+   * @see \Drupal\package_manager\Validator\LockFileValidator
+   */
+  public function recordInstalledPackages(PreCreateEvent $event): void {
+    $packages = $this->composerInspector->getInstalledPackagesList($this->pathLocator->getProjectRoot());
+    $event->stage->setMetadata(static::INSTALLED_PACKAGES_KEY, $packages);
+  }
+
+  /**
+   * Records requested packages.
+   *
+   * @param \Drupal\package_manager\Event\PreRequireEvent $event
+   *   The event object.
+   */
+  public function recordRequestedPackageVersions(PostRequireEvent $event): void {
+    // There could be multiple require operations, so overlay the requested
+    // packages from the current operation onto the requested packages from any
+    // previous require operation.
+    $requested_packages = array_merge(
+      $event->stage->getMetadata(static::REQUESTED_PACKAGES_KEY) ?? [],
+      $event->getRuntimePackages(),
+      $event->getDevPackages(),
+    );
+    $event->stage->setMetadata(static::REQUESTED_PACKAGES_KEY, $requested_packages);
+  }
+
+  /**
+   * Logs all Package Manager changes.
+   *
+   * @param \Drupal\package_manager\Event\PostApplyEvent $event
+   *   The event being handled.
+   */
+  public function logChanges(PostApplyEvent $event): void {
+    $installed_at_start = $event->stage->getMetadata(static::INSTALLED_PACKAGES_KEY);
+    $installed_post_apply = $this->composerInspector->getInstalledPackagesList($this->pathLocator->getProjectRoot());
+
+    // Compare the packages which were installed when the stage was created
+    // against the package versions that were requested over all of the stage's
+    // require operations, and create a log entry listing all of it.
+    $requested_log = [];
+
+    $requested_packages = $event->stage->getMetadata(static::REQUESTED_PACKAGES_KEY) ?? [];
+    // Sort the requested packages by name, to make it easier to review a large
+    // change list.
+    ksort($requested_packages, SORT_NATURAL);
+    foreach ($requested_packages as $name => $constraint) {
+      $installed_version = $installed_at_start[$name]?->version;
+      if ($installed_version === NULL) {
+        // For clarity, make the "any version" constraint human-readable.
+        if ($constraint === '*') {
+          $constraint = $this->t('* (any version)');
+        }
+        $requested_log[] = $this->t('- Install @name @constraint', [
+          '@name' => $name,
+          '@constraint' => $constraint,
+        ]);
+      }
+      else {
+        $requested_log[] = $this->t('- Update @name from @installed_version to @constraint', [
+          '@name' => $name,
+          '@installed_version' => $installed_version,
+          '@constraint' => $constraint,
+        ]);
+      }
+    }
+    // It's possible that $requested_log will be empty -- for example, a custom
+    // stage that only does removals, or some other operation, and never
+    // dispatches PostRequireEvent.
+    if ($requested_log) {
+      $message = $this->t("Requested changes:\n@change_list", [
+        '@change_list' => implode("\n", array_map('strval', $requested_log)),
+      ]);
+      $this->logger->info($message);
+    }
+
+    // Create a separate log entry listing everything that actually changed.
+    $applied_log = [];
+
+    $updated_packages = $installed_post_apply->getPackagesWithDifferentVersionsIn($installed_at_start);
+    // Sort the packages by name to make it easier to review large change sets.
+    $updated_packages->ksort(SORT_NATURAL);
+    foreach ($updated_packages as $name => $package) {
+      $applied_log[] = $this->t('- Updated @name from @installed_version to @updated_version', [
+        '@name' => $name,
+        '@installed_version' => $installed_at_start[$name]->version,
+        '@updated_version' => $package->version,
+      ]);
+    }
+
+    $added_packages = $installed_post_apply->getPackagesNotIn($installed_at_start);
+    $added_packages->ksort(SORT_NATURAL);
+    foreach ($added_packages as $name => $package) {
+      $applied_log[] = $this->t('- Installed @name @version', [
+        '@name' => $name,
+        '@version' => $package->version,
+      ]);
+    }
+
+    $removed_packages = $installed_at_start->getPackagesNotIn($installed_post_apply);
+    $removed_packages->ksort(SORT_NATURAL);
+    foreach ($installed_at_start->getPackagesNotIn($installed_post_apply) as $name => $package) {
+      $applied_log[] = $this->t('- Uninstalled @name', ['@name' => $name]);
+    }
+    $message = $this->t("Applied changes:\n@change_list", [
+      '@change_list' => implode("\n", array_map('strval', $applied_log)),
+    ]);
+    $this->logger->info($message);
+  }
+
+  /**
+   * {@inheritdoc}
+   */
+  public static function getSubscribedEvents(): array {
+    return [
+      PreCreateEvent::class => ['recordInstalledPackages'],
+      PostRequireEvent::class => ['recordRequestedPackageVersions'],
+      PostApplyEvent::class => ['logChanges'],
+    ];
+  }
+
+}

package_manager/src/PackageManagerServiceProvider.php

@@ -109,6 +109,7 @@ final class PackageManagerServiceProvider extends ServiceProviderBase {
       'request_stack' => 'Symfony\Component\HttpFoundation\RequestStack',
       'theme_handler' => 'Drupal\Core\Extension\ThemeHandlerInterface',
       'cron' => 'Drupal\Core\CronInterface',
+      'logger.factory' => 'Drupal\Core\Logger\LoggerChannelFactoryInterface',
     ];
     foreach ($aliases as $service_id => $alias) {
       if (!$container->hasAlias($alias)) {

package_manager/src/StageBase.php

@@ -223,7 +223,7 @@ abstract class StageBase implements LoggerAwareInterface {
    * @return mixed
    *   The metadata value, or NULL if it is not set.
    */
-  protected function getMetadata(string $key) {
+  public function getMetadata(string $key) {
     $this->checkOwnership();
 
     $metadata = $this->tempStore->get(static::TEMPSTORE_METADATA_KEY) ?: [];
@@ -237,11 +237,13 @@ abstract class StageBase implements LoggerAwareInterface {
    * claimed by its owner, or created during the current request.
    *
    * @param string $key
-   *   The key under which to store the metadata.
+   *   The key under which to store the metadata. To prevent conflicts, it is
+   *   strongly recommended that this be prefixed with the name of the module
+   *   storing the data.
    * @param mixed $data
    *   The metadata to store.
    */
-  protected function setMetadata(string $key, $data): void {
+  public function setMetadata(string $key, $data): void {
     $this->checkOwnership();
 
     $metadata = $this->tempStore->get(static::TEMPSTORE_METADATA_KEY);

package_manager/tests/src/Build/PackageInstallTest.php

@@ -42,6 +42,8 @@ class PackageInstallTest extends TemplateProjectTestBase {
       ]
     );
     $this->assertArrayHasKey('web/modules/contrib/alpha/composer.json', $file_contents);
+    $this->assertRequestedChangesWereLogged(['Install drupal/alpha 1.0.0']);
+    $this->assertAppliedChangesWereLogged(['Installed drupal/alpha 1.0.0']);
   }
 
 }

package_manager/tests/src/Build/PackageUpdateTest.php

@@ -76,6 +76,8 @@ class PackageUpdateTest extends TemplateProjectTestBase {
     $this->assertSame('Bravo!', $file_contents['bravo.txt']);
 
     $this->assertExpectedStageEventsFired(ControllerStage::class);
+    $this->assertRequestedChangesWereLogged(['Update drupal/updated_module from 1.0.0 to 1.1.0']);
+    $this->assertAppliedChangesWereLogged(['Updated drupal/updated_module from 1.0.0 to 1.1.0']);
   }
 
 }

package_manager/tests/src/Build/TemplateProjectTestBase.php

@@ -604,6 +604,68 @@ END;
     $this->assertSame($expected_titles, $actual_titles, $message ?? '');
   }
 
+  /**
+   * Visits the 'admin/reports/dblog' and selects Package Manager's change log.
+   */
+  private function visitPackageManagerChangeLog(): void {
+    $mink = $this->getMink();
+    $assert_session = $mink->assertSession();
+    $page = $mink->getSession()->getPage();
+
+    $this->visit('/admin/reports/dblog');
+    $assert_session->statusCodeEquals(200);
+    $page->selectFieldOption('Type', 'package_manager_change_log');
+    $page->pressButton('Filter');
+    $assert_session->statusCodeEquals(200);
+  }
+
+  /**
+   * Asserts changes requested during the stage life cycle were logged.
+   *
+   * This method specifically asserts changes that were *requested* (i.e.,
+   * during the require phase) rather than changes that were actually applied.
+   * The requested and applied changes may be exactly the same, or they may
+   * differ (for example, if a secondary dependency was added or updated in the
+   * stage directory).
+   *
+   * @param string[] $expected_requested_changes
+   *   The expected requested changes.
+   *
+   * @see ::assertAppliedChangesWereLogged()
+   * @see \Drupal\package_manager\EventSubscriber\ChangeLogger
+   */
+  protected function assertRequestedChangesWereLogged(array $expected_requested_changes): void {
+    $this->visitPackageManagerChangeLog();
+    $assert_session = $this->getMink()->assertSession();
+
+    $assert_session->elementExists('css', 'a[href*="/admin/reports/dblog/event/"]:contains("Requested changes:")')
+      ->click();
+    array_walk($expected_requested_changes, $assert_session->pageTextContains(...));
+  }
+
+  /**
+   * Asserts that changes applied during the stage life cycle were logged.
+   *
+   * This method specifically asserts changes that were *applied*, rather than
+   * the changes that were merely requested. For example, if a package was
+   * required into the stage and it added a secondary dependency, that change
+   * will be considered one of the applied changes, not a requested change.
+   *
+   * @param string[] $expected_applied_changes
+   *   The expected applied changes.
+   *
+   * @see ::assertRequestedChangesWereLogged()
+   * @see \Drupal\package_manager\EventSubscriber\ChangeLogger
+   */
+  protected function assertAppliedChangesWereLogged(array $expected_applied_changes): void {
+    $this->visitPackageManagerChangeLog();
+    $assert_session = $this->getMink()->assertSession();
+
+    $assert_session->elementExists('css', 'a[href*="/admin/reports/dblog/event/"]:contains("Applied changes:")')
+      ->click();
+    array_walk($expected_applied_changes, $assert_session->pageTextContains(...));
+  }
+
   /**
    * Gets a /package-manager-test-api response.
    *

package_manager/tests/src/Kernel/ChangeLoggerTest.php

+<?php
+
+namespace Drupal\Tests\package_manager\Kernel;
+
+use ColinODell\PsrTestLogger\TestLogger;
+use Drupal\Core\DependencyInjection\ContainerBuilder;
+use Drupal\fixture_manipulator\ActiveFixtureManipulator;
+use Drupal\package_manager\EventSubscriber\ChangeLogger;
+use Psr\Log\LogLevel;
+
+/**
+ * @covers \Drupal\package_manager\EventSubscriber\ChangeLogger
+ * @group package_manager
+ */
+class ChangeLoggerTest extends PackageManagerKernelTestBase {
+
+  /**
+   * The logger to which change lists will be written.
+   *
+   * @var \ColinODell\PsrTestLogger\TestLogger
+   */
+  private TestLogger $logger;
+
+  /**
+   * {@inheritdoc}
+   */
+  protected function setUp(): void {
+    $this->logger = new TestLogger();
+    parent::setUp();
+  }
+
+  /**
+   * {@inheritdoc}
+   */
+  public function register(ContainerBuilder $container) {
+    parent::register($container);
+
+    $container->getDefinition(ChangeLogger::class)
+      ->setMethodCalls([
+        ['setLogger', [$this->logger]],
+      ]);
+  }
+
+  /**
+   * Tests that the requested and applied changes are logged.
+   */
+  public function testChangeLogging(): void {
+    $this->setReleaseMetadata([
+      'semver_test' => __DIR__ . '/../../fixtures/release-history/semver_test.1.1.xml',
+    ]);
+
+    (new ActiveFixtureManipulator())
+      ->addPackage([
+        'name' => 'package/removed',
+        'type' => 'library',
+      ])
+      ->commitChanges();
+
+    $this->getStageFixtureManipulator()
+      ->setCorePackageVersion('9.8.1')
+      ->addPackage([
+        'name' => 'drupal/semver_test',
+        'type' => 'drupal-module',
+        'version' => '8.1.1',
+      ])
+      ->removePackage('package/removed');
+
+    $stage = $this->createStage();
+    $stage->create();
+    $stage->require([
+      'drupal/semver_test:*',
+      'drupal/core-recommended:^9.8.1',
+    ]);
+    // Nothing should be logged until post-apply.
+    $stage->apply();
+    $this->assertEmpty($this->logger->records);
+    $stage->postApply();
+
+    $this->assertTrue($this->logger->hasInfoRecords());
+    $records = $this->logger->recordsByLevel[LogLevel::INFO];
+    $this->assertCount(2, $records);
+    // The first record should be of the requested changes.
+    $expected_message = <<<END
+Requested changes:
+- Update drupal/core-recommended from 9.8.0 to ^9.8.1
+- Install drupal/semver_test * (any version)
+END;
+    $this->assertSame($expected_message, (string) $records[0]['message']);
+
+    // The second record should be of the actual changes.
+    $expected_message = <<<END
+Applied changes:
+- Updated drupal/core from 9.8.0 to 9.8.1
+- Updated drupal/core-dev from 9.8.0 to 9.8.1
+- Updated drupal/core-recommended from 9.8.0 to 9.8.1
+- Installed drupal/semver_test 8.1.1
+- Uninstalled package/removed
+END;
+    $this->assertSame($expected_message, (string) $records[1]['message']);
+  }
+
+}

package_manager/tests/src/Kernel/StageBaseTest.php

@@ -56,6 +56,43 @@ class StageBaseTest extends PackageManagerKernelTestBase {
     $container->getDefinition('event_dispatcher')->addTag('persist');
   }
 
+  /**
+   * @covers ::getMetadata
+   * @covers ::setMetadata
+   */
+  public function testMetadata(): void {
+    $stage = $this->createStage();
+    $stage->create();
+    $this->assertNull($stage->getMetadata('new_key'));
+    $stage->setMetadata('new_key', 'value');
+    $this->assertSame('value', $stage->getMetadata('new_key'));
+    $stage->destroy();
+
+    // Ensure that metadata associated with the previous stage was deleted.
+    $stage = $this->createStage();
+    $stage->create();
+    $this->assertNull($stage->getMetadata('new_key'));
+    $stage->destroy();
+
+    // Ensure metadata cannot be get or set unless the stage has been claimed.
+    $stage = $this->createStage();
+    try {
+      $stage->getMetadata('new_key');
+      $this->fail('Expected an ownership exception, but none was thrown.');
+    }
+    catch (\LogicException $e) {
+      $this->assertSame('Stage must be claimed before performing any operations on it.', $e->getMessage());
+    }
+
+    try {
+      $stage->setMetadata('new_key', 'value');
+      $this->fail('Expected an ownership exception, but none was thrown.');
+    }
+    catch (\LogicException $e) {
+      $this->assertSame('Stage must be claimed before performing any operations on it.', $e->getMessage());
+    }
+  }
+
   /**
    * @covers ::getStageDirectory
    */

tests/src/Build/CoreUpdateTest.php

@@ -139,6 +139,16 @@ class CoreUpdateTest extends UpdateTestBase {
 
     $this->assertStringContainsString("const VERSION = '9.8.1';", $file_contents['web/core/lib/Drupal.php']);
     $this->assertUpdateSuccessful('9.8.1');
+
+    $this->assertRequestedChangesWereLogged([
+      'Update drupal/core-dev from 9.8.0 to 9.8.1',
+      'Update drupal/core-recommended from 9.8.0 to 9.8.1',
+    ]);
+    $this->assertAppliedChangesWereLogged([
+      'Updated drupal/core from 9.8.0 to 9.8.1',
+      'Updated drupal/core-dev from 9.8.0 to 9.8.1',
+      'Updated drupal/core-recommended from 9.8.0 to 9.8.1',
+    ]);
   }
 
   /**
@@ -160,6 +170,15 @@ class CoreUpdateTest extends UpdateTestBase {
     $assert_session->pageTextNotContains('There is a security update available for your version of Drupal.');
     $this->assertExpectedStageEventsFired(UpdateStage::class);
     $this->assertUpdateSuccessful('9.8.1');
+    $this->assertRequestedChangesWereLogged([
+      'Update drupal/core-dev from 9.8.0 to 9.8.1',
+      'Update drupal/core-recommended from 9.8.0 to 9.8.1',
+    ]);
+    $this->assertAppliedChangesWereLogged([
+      'Updated drupal/core from 9.8.0 to 9.8.1',
+      'Updated drupal/core-dev from 9.8.0 to 9.8.1',
+      'Updated drupal/core-recommended from 9.8.0 to 9.8.1',
+    ]);
   }
 
   /**

tests/src/Kernel/AutomaticUpdatesKernelTestBase.php

@@ -5,7 +5,6 @@ declare(strict_types = 1);
 namespace Drupal\Tests\automatic_updates\Kernel;
 
 use Drupal\automatic_updates\CronUpdateStage;
-use Drupal\automatic_updates\UpdateStage;
 use Drupal\Core\DependencyInjection\ContainerBuilder;
 use Drupal\Tests\automatic_updates\Traits\ValidationTestTrait;
 use Drupal\Tests\package_manager\Kernel\PackageManagerKernelTestBase;
@@ -84,7 +83,6 @@ abstract class AutomaticUpdatesKernelTestBase extends PackageManagerKernelTestBa
 
     // Use the test-only implementations of the regular and cron update stages.
     $overrides = [
-      'automatic_updates.update_stage' => TestUpdateStage::class,
       'automatic_updates.cron_update_stage' => TestCronUpdateStage::class,
     ];
     foreach ($overrides as $service_id => $class) {
@@ -96,20 +94,6 @@ abstract class AutomaticUpdatesKernelTestBase extends PackageManagerKernelTestBa
 
 }
 
-/**
- * A test-only version of the regular update stage to override internals.
- */
-class TestUpdateStage extends UpdateStage {
-
-  /**
-   * {@inheritdoc}
-   */
-  public function setMetadata(string $key, $data): void {
-    parent::setMetadata($key, $data);
-  }
-
-}
-
 /**
  * A test-only version of the cron update stage to override and expose internals.
  */
@@ -124,11 +108,4 @@ class TestCronUpdateStage extends CronUpdateStage {
     $this->handlePostApply($stage_id, $start_version, $target_version);
   }
 
-  /**
-   * {@inheritdoc}
-   */
-  public function setMetadata(string $key, $data): void {
-    parent::setMetadata($key, $data);
-  }
-
 }