diff --git a/migrations/Version20260513120000.php b/migrations/Version20260513120000.php new file mode 100644 index 00000000..25b189a4 --- /dev/null +++ b/migrations/Version20260513120000.php @@ -0,0 +1,58 @@ +addSql('DROP TABLE IF EXISTS logging'); + + $this->addSql('CREATE TABLE logging ( + id INT AUTO_INCREMENT NOT NULL, + user_id INT DEFAULT NULL, + username VARCHAR(180) DEFAULT NULL, + date DATETIME NOT NULL COMMENT \'(DC2Type:datetime_immutable)\', + entity_class VARCHAR(255) NOT NULL, + entity_id VARCHAR(64) DEFAULT NULL, + action VARCHAR(16) NOT NULL, + changes JSON DEFAULT NULL, + ip_address VARCHAR(45) DEFAULT NULL, + INDEX idx_logging_date (date), + INDEX idx_logging_entity (entity_class, entity_id), + INDEX idx_logging_user (user_id), + PRIMARY KEY(id) + ) DEFAULT CHARACTER SET utf8mb4 COLLATE `utf8mb4_unicode_ci` ENGINE = InnoDB'); + + $this->addSql('ALTER TABLE logging + ADD CONSTRAINT FK_logging_user FOREIGN KEY (user_id) REFERENCES users (id) ON DELETE SET NULL'); + } + + public function down(Schema $schema): void + { + $this->addSql('ALTER TABLE logging DROP FOREIGN KEY FK_logging_user'); + $this->addSql('DROP TABLE IF EXISTS logging'); + + $this->addSql('CREATE TABLE logging ( + user_id INT NOT NULL, + date TIME NOT NULL, + action VARCHAR(255) NOT NULL, + PRIMARY KEY(user_id) + ) DEFAULT CHARACTER SET utf8mb4 COLLATE `utf8mb4_unicode_ci` ENGINE = InnoDB'); + } + + public function isTransactional(): bool + { + return false; + } +} diff --git a/src/Command/PurgeLogsCommand.php b/src/Command/PurgeLogsCommand.php new file mode 100644 index 00000000..81ccb654 --- /dev/null +++ b/src/Command/PurgeLogsCommand.php @@ -0,0 +1,64 @@ +addOption('days', null, InputOption::VALUE_REQUIRED, 'Delete audit and workflow log entries older than this many days.', 90); + } + + protected function execute(InputInterface $input, OutputInterface $output): int + { + $io = new SymfonyStyle($input, $output); + + if ('workflow:purge-logs' === $input->getFirstArgument()) { + $io->warning('The "workflow:purge-logs" command is deprecated and will be removed in a future release. Use "app:purge-logs" instead.'); + } + + $days = filter_var($input->getOption('days'), FILTER_VALIDATE_INT); + + if (false === $days || $days <= 0) { + $io->error('--days must be a positive integer.'); + + return Command::FAILURE; + } + + $before = new \DateTimeImmutable('-'.$days.' days'); + $audit = $this->logRepository->purgeOlderThan($before); + $workflow = $this->workflowLogRepository->purgeOlderThan($before); + + $io->success(sprintf( + 'Deleted %d audit log and %d workflow log entries older than %d days.', + $audit, + $workflow, + $days, + )); + + return Command::SUCCESS; + } +} diff --git a/src/Command/PurgeWorkflowLogsCommand.php b/src/Command/PurgeWorkflowLogsCommand.php deleted file mode 100644 index b8d6453d..00000000 --- a/src/Command/PurgeWorkflowLogsCommand.php +++ /dev/null @@ -1,50 +0,0 @@ -addOption('days', null, InputOption::VALUE_REQUIRED, 'Delete log entries older than this many days.', 90); - } - - protected function execute(InputInterface $input, OutputInterface $output): int - { - $io = new SymfonyStyle($input, $output); - $days = (int) $input->getOption('days'); - - if ($days <= 0) { - $io->error('--days must be a positive integer.'); - - return Command::FAILURE; - } - - $before = new \DateTimeImmutable('-' . $days . ' days'); - $deleted = $this->logRepository->purgeOlderThan($before); - - $io->success(sprintf('Deleted %d log entries older than %d days.', $deleted, $days)); - - return Command::SUCCESS; - } -} diff --git a/src/Entity/Enum/LogAction.php b/src/Entity/Enum/LogAction.php new file mode 100644 index 00000000..567678df --- /dev/null +++ b/src/Entity/Enum/LogAction.php @@ -0,0 +1,12 @@ +user_id = $userId; + private ?int $id = null; + + #[ORM\ManyToOne(targetEntity: User::class)] + #[ORM\JoinColumn(name: 'user_id', referencedColumnName: 'id', nullable: true, onDelete: 'SET NULL')] + private ?User $user = null; + + #[ORM\Column(type: 'string', length: 180, nullable: true)] + private ?string $username = null; + + #[ORM\Column(type: 'datetime_immutable')] + private \DateTimeImmutable $date; + + #[ORM\Column(name: 'entity_class', type: 'string', length: 255)] + private string $entityClass; + + #[ORM\Column(name: 'entity_id', type: 'string', length: 64, nullable: true)] + private ?string $entityId = null; + + #[ORM\Column(type: 'string', length: 16, enumType: LogAction::class)] + private LogAction $action; + + /** @var array|null */ + #[ORM\Column(type: 'json', nullable: true)] + private ?array $changes = null; + + #[ORM\Column(name: 'ip_address', type: 'string', length: 45, nullable: true)] + private ?string $ipAddress = null; + + public function getId(): ?int + { + return $this->id; + } + + public function getUser(): ?User + { + return $this->user; + } + + public function setUser(?User $user): self + { + $this->user = $user; return $this; } - /** - * Get user_id. - * - * @return int - */ - public function getUserId() + public function getUsername(): ?string { - return $this->user_id; + return $this->username; } - /** - * Set date. - * - * @param \DateTime $date - * - * @return Log - */ - public function setDate($date) + public function setUsername(?string $username): self { - $this->date = $date; + $this->username = $username; return $this; } - /** - * Get date. - * - * @return \DateTime - */ - public function getDate() + public function getDate(): \DateTimeImmutable { return $this->date; } - /** - * Set action. - * - * @param string $action - * - * @return Log - */ - public function setAction($action) + public function setDate(\DateTimeImmutable $date): self { - $this->action = $action; + $this->date = $date; + + return $this; + } + + public function getEntityClass(): string + { + return $this->entityClass; + } + + public function setEntityClass(string $entityClass): self + { + $this->entityClass = $entityClass; return $this; } - /** - * Get action. - * - * @return string - */ - public function getAction() + public function getEntityId(): ?string + { + return $this->entityId; + } + + public function setEntityId(?string $entityId): self + { + $this->entityId = $entityId; + + return $this; + } + + public function getAction(): LogAction { return $this->action; } + + public function setAction(LogAction $action): self + { + $this->action = $action; + + return $this; + } + + /** @return array|null */ + public function getChanges(): ?array + { + return $this->changes; + } + + /** @param array|null $changes */ + public function setChanges(?array $changes): self + { + $this->changes = $changes; + + return $this; + } + + public function getIpAddress(): ?string + { + return $this->ipAddress; + } + + public function setIpAddress(?string $ipAddress): self + { + $this->ipAddress = $ipAddress; + + return $this; + } } diff --git a/src/EventListener/EntityChangeLogListener.php b/src/EventListener/EntityChangeLogListener.php new file mode 100644 index 00000000..42edcb5c --- /dev/null +++ b/src/EventListener/EntityChangeLogListener.php @@ -0,0 +1,294 @@ +}> */ + private array $buffer = []; + + public function __construct( + private readonly ManagerRegistry $registry, + private readonly Security $security, + private readonly RequestStack $requestStack, + ) { + } + + public function onFlush(OnFlushEventArgs $args): void + { + $em = $args->getObjectManager(); + if (!$this->isPrimaryEm($em)) { + return; + } + + $uow = $em->getUnitOfWork(); + + foreach ($uow->getScheduledEntityInsertions() as $entity) { + if ($this->isIgnored($entity)) { + continue; + } + $this->buffer[] = [ + 'action' => LogAction::CREATE, + 'entity' => $entity, + 'class' => $em->getClassMetadata($entity::class)->getName(), + 'id' => $this->getEntityId($entity, $em), + 'changes' => $this->filterNoise($uow->getEntityChangeSet($entity)), + ]; + } + + foreach ($uow->getScheduledEntityUpdates() as $entity) { + if ($this->isIgnored($entity)) { + continue; + } + $changes = $this->filterNoise($uow->getEntityChangeSet($entity)); + if ([] === $changes) { + continue; + } + $this->buffer[] = [ + 'action' => LogAction::UPDATE, + 'entity' => $entity, + 'class' => $em->getClassMetadata($entity::class)->getName(), + 'id' => $this->getEntityId($entity, $em), + 'changes' => $changes, + ]; + } + + foreach ($uow->getScheduledEntityDeletions() as $entity) { + if ($this->isIgnored($entity)) { + continue; + } + $this->buffer[] = [ + 'action' => LogAction::DELETE, + 'entity' => $entity, + 'class' => $em->getClassMetadata($entity::class)->getName(), + 'id' => $this->getEntityId($entity, $em), + 'changes' => $this->snapshot($entity, $em), + ]; + } + } + + public function postFlush(PostFlushEventArgs $args): void + { + if ([] === $this->buffer) { + return; + } + + $em = $args->getObjectManager(); + if (!$this->isPrimaryEm($em)) { + return; + } + + $buffer = $this->buffer; + $this->buffer = []; + + $user = $this->security->getUser(); + $username = $user instanceof User ? $user->getUserIdentifier() : null; + $userId = $user instanceof User ? $user->getId() : null; + $ip = $this->requestStack->getCurrentRequest()?->getClientIp(); + $now = new \DateTimeImmutable(); + + // Write Log rows through the `background` EM (same pattern as + // LastActionSubscriber): keeps audit writes isolated from the main flush + // cycle so they cannot trigger this listener again or accidentally pick + // up unrelated dirty entities. + try { + $logEm = $this->registry->getManager('background'); + if (!$logEm instanceof EntityManagerInterface || !$logEm->isOpen()) { + $logEm = $this->registry->resetManager('background'); + } + if (!$logEm instanceof EntityManagerInterface) { + return; + } + + $userRef = null !== $userId ? $logEm->getReference(User::class, $userId) : null; + + foreach ($buffer as $item) { + $log = new Log(); + $log->setDate($now); + $log->setEntityClass($item['class']); + $log->setEntityId($item['id'] ?? $this->getEntityId($item['entity'], $em)); + $log->setAction($item['action']); + $log->setChanges($this->sanitize($item['changes'])); + $log->setUser($userRef); + $log->setUsername($username); + $log->setIpAddress($ip); + $logEm->persist($log); + } + $logEm->flush(); + $logEm->clear(); + } catch (\Throwable) { + // best-effort: never block the request for audit-log writes. + } + } + + private function isPrimaryEm(object $em): bool + { + return $em === $this->registry->getManager('default'); + } + + private function isIgnored(object $entity): bool + { + foreach (self::IGNORED_ENTITIES as $cls) { + if ($entity instanceof $cls) { + return true; + } + } + + return false; + } + + /** + * @param array $changes + * + * @return array + */ + private function filterNoise(array $changes): array + { + foreach (self::NOISY_FIELDS as $field) { + unset($changes[$field]); + } + + return $changes; + } + + private function getEntityId(object $entity, EntityManagerInterface $em): ?string + { + $meta = $em->getClassMetadata($entity::class); + $ids = $meta->getIdentifierValues($entity); + if ([] === $ids) { + return null; + } + + $parts = []; + foreach ($ids as $id) { + $parts[] = is_scalar($id) ? (string) $id : (string) $this->normalize($id); + } + + return implode(',', $parts); + } + + /** + * @return array + */ + private function snapshot(object $entity, EntityManagerInterface $em): array + { + $meta = $em->getClassMetadata($entity::class); + $snapshot = []; + foreach ($meta->getFieldNames() as $field) { + $snapshot[$field] = [$meta->getFieldValue($entity, $field), null]; + } + + return $this->filterNoise($snapshot); + } + + /** + * @param array $changes + * + * @return array + */ + private function sanitize(array $changes): array + { + $out = []; + foreach ($changes as $field => $values) { + if ($this->isSensitive($field)) { + $out[$field] = ['***redacted***', '***redacted***']; + continue; + } + $out[$field] = [$this->normalize($values[0] ?? null), $this->normalize($values[1] ?? null)]; + } + + return $out; + } + + private function isSensitive(string $field): bool + { + $lower = strtolower($field); + foreach (self::SENSITIVE_FIELD_NEEDLES as $needle) { + if (str_contains($lower, $needle)) { + return true; + } + } + + return false; + } + + private function normalize(mixed $value): mixed + { + if (null === $value) { + return null; + } + if ($value instanceof \DateTimeInterface) { + return $value->format(\DateTimeInterface::ATOM); + } + if (is_object($value)) { + $cls = $this->shortClass($value::class); + if (method_exists($value, 'getId') && null !== $value->getId()) { + return $cls.'#'.(string) $value->getId(); + } + if ($value instanceof \BackedEnum) { + return (string) $value->value; + } + + return $cls; + } + if (is_array($value) || $value instanceof \Countable) { + return sprintf('array(%d)', count($value)); + } + if (is_string($value)) { + $value = preg_replace('/[\x00-\x08\x0B\x0C\x0E-\x1F\x7F]/', '?', $value); + if (mb_strlen($value) > self::MAX_STRING_LENGTH) { + $value = mb_substr($value, 0, self::MAX_STRING_LENGTH).'…(truncated)'; + } + + return $value; + } + + return $value; + } + + private function shortClass(string $fqcn): string + { + $pos = strrpos($fqcn, '\\'); + + return false === $pos ? $fqcn : substr($fqcn, $pos + 1); + } +} diff --git a/src/Repository/LogRepository.php b/src/Repository/LogRepository.php new file mode 100644 index 00000000..f108fb51 --- /dev/null +++ b/src/Repository/LogRepository.php @@ -0,0 +1,35 @@ + + * + * @method Log|null find($id, $lockMode = null, $lockVersion = null) + * @method Log|null findOneBy(array $criteria, array $orderBy = null) + * @method Log[] findAll() + * @method Log[] findBy(array $criteria, array $orderBy = null, $limit = null, $offset = null) + */ +class LogRepository extends ServiceEntityRepository +{ + public function __construct(ManagerRegistry $registry) + { + parent::__construct($registry, Log::class); + } + + public function purgeOlderThan(\DateTimeImmutable $before): int + { + return $this->createQueryBuilder('l') + ->delete() + ->where('l.date < :before') + ->setParameter('before', $before) + ->getQuery() + ->execute(); + } +} diff --git a/tests/Functional/EntityChangeLogListenerTest.php b/tests/Functional/EntityChangeLogListenerTest.php new file mode 100644 index 00000000..7cc1ab27 --- /dev/null +++ b/tests/Functional/EntityChangeLogListenerTest.php @@ -0,0 +1,183 @@ +get(ManagerRegistry::class); + $em = $registry->getManager(); + assert($em instanceof EntityManagerInterface); + $this->em = $em; + $this->conn = $em->getConnection(); + $this->conn->executeStatement('DELETE FROM logging'); + } + + public function testCreateLogsAnInsertRowWithSnapshotChangeset(): void + { + $customer = $this->newCustomer('Audit', 'Create'); + $this->em->persist($customer); + $this->em->flush(); + + $rows = $this->fetchLog(); + self::assertCount(1, $rows); + self::assertSame('create', $rows[0]['action']); + self::assertSame(Customer::class, $rows[0]['entity_class']); + self::assertSame((string) $customer->getId(), $rows[0]['entity_id']); + + $changes = $this->decode($rows[0]['changes']); + self::assertSame([null, 'Audit'], $changes['firstname']); + self::assertSame([null, 'Create'], $changes['lastname']); + } + + public function testUpdateLogsOnlyChangedFields(): void + { + $customer = $this->newCustomer('Before', 'Same'); + $this->em->persist($customer); + $this->em->flush(); + $this->conn->executeStatement('DELETE FROM logging'); + + $customer->setFirstname('After'); + $this->em->flush(); + + $rows = $this->fetchLog(); + self::assertCount(1, $rows); + self::assertSame('update', $rows[0]['action']); + + $changes = $this->decode($rows[0]['changes']); + self::assertSame(['firstname' => ['Before', 'After']], $changes, + 'Update diff must contain only the modified field — no untouched fields.'); + } + + public function testDeleteLogsPreDeletionSnapshot(): void + { + $customer = $this->newCustomer('ToDelete', 'Smoke'); + $this->em->persist($customer); + $this->em->flush(); + $customerId = (string) $customer->getId(); + $this->conn->executeStatement('DELETE FROM logging'); + + $this->em->remove($customer); + $this->em->flush(); + + $rows = $this->fetchLog(); + self::assertCount(1, $rows); + self::assertSame('delete', $rows[0]['action']); + self::assertSame($customerId, $rows[0]['entity_id'], + 'Delete row must capture the entity id BEFORE the row is gone.'); + + $changes = $this->decode($rows[0]['changes']); + self::assertSame(['ToDelete', null], $changes['firstname']); + self::assertSame(['Smoke', null], $changes['lastname']); + } + + public function testSensitiveFieldsAreRedacted(): void + { + $user = $this->em->getRepository(User::class)->findOneBy(['username' => 'test-admin']); + self::assertInstanceOf(User::class, $user, 'Test user "test-admin" must exist (run bin/run-tests.sh).'); + + $originalPassword = $user->getPassword(); + $newPassword = 'tmp-hash-'.bin2hex(random_bytes(8)); + $user->setPassword($newPassword); + $this->em->flush(); + + $rows = $this->fetchLog(); + self::assertCount(1, $rows); + $changes = $this->decode($rows[0]['changes']); + self::assertArrayHasKey('password', $changes, 'A password change still produces a diff entry, just redacted.'); + self::assertSame(['***redacted***', '***redacted***'], $changes['password']); + self::assertStringNotContainsString($newPassword, $rows[0]['changes'], + 'The literal password value must never appear in the serialized log row.'); + + // restore so subsequent fast-loop runs (make phpunit) still see a real diff + $user->setPassword($originalPassword); + $this->em->flush(); + } + + public function testLastActionUpdatesAreFilteredOutOfTheDiff(): void + { + $user = $this->em->getRepository(User::class)->findOneBy(['username' => 'test-admin']); + self::assertInstanceOf(User::class, $user); + + $originalFirstname = $user->getFirstname(); + $user->setLastAction(new \DateTime('2026-05-13 09:00:00')); + $user->setFirstname('FilteredUpdate'); + $this->em->flush(); + + $rows = $this->fetchLog(); + self::assertCount(1, $rows); + $changes = $this->decode($rows[0]['changes']); + self::assertArrayHasKey('firstname', $changes); + self::assertArrayNotHasKey('lastAction', $changes, + 'lastAction is touched on every request by LastActionSubscriber; the listener must scrub it from update diffs.'); + + // restore original to keep test fixtures stable for subsequent tests + $user->setFirstname($originalFirstname); + $this->em->flush(); + } + + public function testLastActionOnlyUpdateProducesNoLogRow(): void + { + $user = $this->em->getRepository(User::class)->findOneBy(['username' => 'test-admin']); + self::assertInstanceOf(User::class, $user); + + $user->setLastAction(new \DateTime('2026-05-13 09:05:00')); + $this->em->flush(); + + self::assertCount(0, $this->fetchLog(), + 'An update whose only delta is a filtered field must not produce a log row at all.'); + } + + private function newCustomer(string $first, string $last): Customer + { + $customer = new Customer(); + $customer->setSalutation('Mr'); + $customer->setFirstname($first); + $customer->setLastname($last); + + return $customer; + } + + /** + * @return list> + */ + private function fetchLog(): array + { + return $this->conn + ->executeQuery('SELECT action, entity_class, entity_id, changes FROM logging ORDER BY id') + ->fetchAllAssociative(); + } + + /** + * @return array + */ + private function decode(mixed $json): array + { + self::assertIsString($json); + $decoded = json_decode($json, true, flags: JSON_THROW_ON_ERROR); + self::assertIsArray($decoded); + + return $decoded; + } +} diff --git a/tests/Functional/PurgeLogsCommandTest.php b/tests/Functional/PurgeLogsCommandTest.php new file mode 100644 index 00000000..47491575 --- /dev/null +++ b/tests/Functional/PurgeLogsCommandTest.php @@ -0,0 +1,107 @@ +get(ManagerRegistry::class); + $em = $registry->getManager(); + assert($em instanceof EntityManagerInterface); + $this->conn = $em->getConnection(); + + $this->conn->executeStatement('DELETE FROM logging'); + $this->conn->executeStatement('DELETE FROM workflow_logs'); + + $application = new Application($kernel); + $this->tester = new CommandTester($application->find('app:purge-logs')); + } + + public function testPurgesOldRowsAndPiiAcrossBothLogTables(): void + { + $oldDate = (new \DateTimeImmutable('-100 days'))->format('Y-m-d H:i:s'); + $recentDate = (new \DateTimeImmutable('-5 days'))->format('Y-m-d H:i:s'); + + $this->insertAuditLog($oldDate, ipAddress: '203.0.113.42', username: 'alice'); + $this->insertAuditLog($recentDate, ipAddress: '203.0.113.99', username: 'bob'); + $this->insertWorkflowLog($oldDate); + $this->insertWorkflowLog($recentDate); + + $exit = $this->tester->execute(['--days' => 90]); + + self::assertSame(0, $exit); + self::assertSame(1, (int) $this->conn->fetchOne('SELECT COUNT(*) FROM logging')); + self::assertSame(1, (int) $this->conn->fetchOne('SELECT COUNT(*) FROM workflow_logs')); + self::assertStringContainsString('Deleted 1 audit log and 1 workflow log', $this->tester->getDisplay()); + + // GDPR-relevant: the IP/username of the purged row must be gone, only the recent row's PII remains. + $remainingIps = $this->conn->fetchFirstColumn('SELECT ip_address FROM logging'); + self::assertSame(['203.0.113.99'], $remainingIps, + 'The IP address from the purged row must no longer exist anywhere in the logging table.'); + } + + public function testLegacyAliasEmitsDeprecationWarning(): void + { + $exit = $this->tester->execute(['command' => 'workflow:purge-logs', '--days' => 90]); + + self::assertSame(0, $exit); + self::assertStringContainsString('"workflow:purge-logs" command is deprecated', $this->tester->getDisplay(), + 'Invoking the legacy alias must print a deprecation notice so admins know to migrate their crontab.'); + } + + public function testRejectsNonPositiveDays(): void + { + $exit = $this->tester->execute(['--days' => 0]); + + self::assertSame(1, $exit); + self::assertStringContainsString('--days must be a positive integer', $this->tester->getDisplay()); + } + + public function testRejectsNonNumericDays(): void + { + $exit = $this->tester->execute(['--days' => 'forever']); + + self::assertSame(1, $exit); + self::assertStringContainsString('--days must be a positive integer', $this->tester->getDisplay()); + } + + private function insertAuditLog(string $date, ?string $ipAddress = null, ?string $username = null): void + { + $this->conn->insert('logging', [ + 'date' => $date, + 'entity_class' => 'App\\Entity\\Customer', + 'entity_id' => '1', + 'action' => 'create', + 'changes' => null, + 'ip_address' => $ipAddress, + 'username' => $username, + ]); + } + + private function insertWorkflowLog(string $executedAt): void + { + $this->conn->insert('workflow_logs', [ + 'workflow_name' => 'test-workflow', + 'trigger_type' => 'manual', + 'status' => 'success', + 'executed_at' => $executedAt, + ]); + } +}