diff --git a/doc/audit-log.md b/doc/audit-log.md index 7838048..4dad029 100644 --- a/doc/audit-log.md +++ b/doc/audit-log.md @@ -89,6 +89,19 @@ Table non geree par Doctrine ORM (pas d'entite). Ecriture via DBAL uniquement po - **`performed_by` denormalise** : string, pas FK — le nom persiste meme si l'utilisateur est supprime - **Migration** : dans `migrations/` (namespace racine `DoctrineMigrations`) a cause du bug de tri alphabetique FQCN de Doctrine Migrations 3.x entre namespaces +### Contrat : ce que `audit_log` garantit (et ne garantit pas) + +`audit_log` enregistre les **tentatives de modification** capturees par le `postFlush` Doctrine, ecrites via une connexion DBAL dediee (`audit_connection`). Ce choix est intentionnel : les lignes d'audit survivent au rollback eventuel de la transaction metier principale, ce qui permet de tracer les tentatives meme en cas d'echec applicatif. + +**Conséquence à connaître** : si un controller enveloppe plusieurs operations dans une transaction explicite sur la connexion `default` et que cette transaction outermost rollback apres un flush intermediaire reussi, la ligne audit correspondante **persiste** sur la connexion `audit` alors que la modification metier a ete annulee. L'audit log peut donc contenir des lignes decrivant un etat qui n'existe pas en base metier. + +En pratique : +- Ce cas est rare dans un CRM interne (les rollbacks explicites outermost sont marginaux par rapport aux flushes atomiques). +- La ligne audit garde son `request_id` qui permet une correlation post-mortem avec les logs applicatifs pour distinguer une tentative avortee d'un commit reussi. +- Le comportement est volontaire — pas un bug. Pour un besoin de garantie « audit = reflet exact du commit outermost », il faudrait basculer l'audit sur la meme connexion que le metier (voir `AuditLogWriter`), au prix de perdre la resilience au rollback partiel. + +L'audit est donc un **journal des intentions appliquees par l'ORM**, pas une source de verite transactionnelle sur l'etat final de la DB. + --- ## Composants backend diff --git a/src/Module/Core/Infrastructure/ApiPlatform/State/Provider/AuditLogProvider.php b/src/Module/Core/Infrastructure/ApiPlatform/State/Provider/AuditLogProvider.php index e5fd16c..cc69e85 100644 --- a/src/Module/Core/Infrastructure/ApiPlatform/State/Provider/AuditLogProvider.php +++ b/src/Module/Core/Infrastructure/ApiPlatform/State/Provider/AuditLogProvider.php @@ -15,6 +15,7 @@ use Doctrine\DBAL\ArrayParameterType; use Doctrine\DBAL\Connection; use Doctrine\DBAL\Query\QueryBuilder; use Symfony\Component\DependencyInjection\Attribute\Autowire; +use Symfony\Component\HttpKernel\Exception\BadRequestHttpException; /** * Provider API Platform pour la resource AuditLog. @@ -128,20 +129,42 @@ final readonly class AuditLogProvider implements ProviderInterface } } - foreach (['entity_id', 'action', 'performed_by'] as $key) { + foreach (['entity_id', 'performed_by'] as $key) { if (isset($raw[$key]) && is_string($raw[$key]) && '' !== $raw[$key]) { $filters[$key] = $raw[$key]; } } + // `action` : whitelist stricte. Un input hors-liste provoquait avant + // un simple match vide (resultat 0 ligne) mais permettait d'incrementer + // le log applicatif a chaque variation ; on rejette en 400 explicite. + if (isset($raw['action']) && is_string($raw['action']) && '' !== $raw['action']) { + if (!in_array($raw['action'], ['create', 'update', 'delete'], true)) { + throw new BadRequestHttpException( + 'Filtre "action" invalide : valeurs autorisees create|update|delete.', + ); + } + $filters['action'] = $raw['action']; + } + // Filtres de plage `performed_at[after]` / `performed_at[before]`. + // Sans validation, un input malforme remonte jusqu'a Postgres qui + // leve `SQLSTATE[22007]: invalid input syntax for type timestamp` → + // 500 Internal Server Error, log Monolog pollue, mauvaise UX API. + // On valide en amont et on rejette en 400 explicite. if (isset($raw['performed_at']) && is_array($raw['performed_at'])) { $range = $raw['performed_at']; - if (isset($range['after']) && is_string($range['after']) && '' !== $range['after']) { - $filters['performed_at_after'] = $range['after']; - } - if (isset($range['before']) && is_string($range['before']) && '' !== $range['before']) { - $filters['performed_at_before'] = $range['before']; + foreach (['after', 'before'] as $bound) { + if (!isset($range[$bound]) || !is_string($range[$bound]) || '' === $range[$bound]) { + continue; + } + if (false === strtotime($range[$bound])) { + throw new BadRequestHttpException(sprintf( + 'Filtre "performed_at[%s]" invalide : date ISO 8601 attendue (ex: 2026-04-22T00:00:00Z).', + $bound, + )); + } + $filters['performed_at_'.$bound] = $range[$bound]; } } diff --git a/src/Module/Core/Infrastructure/Doctrine/AuditListener.php b/src/Module/Core/Infrastructure/Doctrine/AuditListener.php index 98b302f..c478cda 100644 --- a/src/Module/Core/Infrastructure/Doctrine/AuditListener.php +++ b/src/Module/Core/Infrastructure/Doctrine/AuditListener.php @@ -102,6 +102,14 @@ final class AuditListener $em = $args->getObjectManager(); $uow = $em->getUnitOfWork(); + // Reset defensif en debut de cycle : si un flush precedent a leve une + // exception, Doctrine n'appelle PAS postFlush et pendingLogs reste + // rempli avec des changements jamais committes. Sans ce reset, un + // flush ulterieur reussi ecrirait les fausses entrees dans audit_log. + // Le swap-and-clear dans postFlush couvre deja les flushes re-entrants, + // ce reset ne le fragilise donc pas. + $this->pendingLogs = []; + foreach ($uow->getScheduledEntityInsertions() as $entity) { $this->capturePendingLog($entity, $em, $uow, 'create'); } diff --git a/tests/Module/Core/Api/AuditLogApiTest.php b/tests/Module/Core/Api/AuditLogApiTest.php index a0e82f7..869da99 100644 --- a/tests/Module/Core/Api/AuditLogApiTest.php +++ b/tests/Module/Core/Api/AuditLogApiTest.php @@ -188,6 +188,27 @@ final class AuditLogApiTest extends AbstractApiTestCase self::assertSame($row['id'], $data['id']); } + /** + * Validation des filtres : un input malforme doit retourner un 400 + * explicite, pas un 500 (Postgres qui rejette le cast timestamp) ni + * un match silencieux sur une valeur inattendue. + */ + public function testInvalidPerformedAtFilterReturns400(): void + { + $client = $this->authenticatedClient('admin', 'admin'); + $response = $client->request('GET', '/api/audit-logs?performed_at[after]=pas-une-date'); + + self::assertSame(400, $response->getStatusCode()); + } + + public function testInvalidActionFilterReturns400(): void + { + $client = $this->authenticatedClient('admin', 'admin'); + $response = $client->request('GET', '/api/audit-logs?action=dropTable'); + + self::assertSame(400, $response->getStatusCode()); + } + public function testPostIsNotAllowed(): void { $client = $this->authenticatedClient('admin', 'admin'); diff --git a/tests/Module/Core/Infrastructure/Doctrine/AuditListenerTest.php b/tests/Module/Core/Infrastructure/Doctrine/AuditListenerTest.php index 8f16cce..d705710 100644 --- a/tests/Module/Core/Infrastructure/Doctrine/AuditListenerTest.php +++ b/tests/Module/Core/Infrastructure/Doctrine/AuditListenerTest.php @@ -7,8 +7,11 @@ namespace App\Tests\Module\Core\Infrastructure\Doctrine; use App\Module\Core\Domain\Entity\Permission; use App\Module\Core\Domain\Entity\Role; use App\Module\Core\Domain\Entity\User; +use App\Module\Core\Infrastructure\Doctrine\AuditListener; use Doctrine\DBAL\Connection; use Doctrine\ORM\EntityManagerInterface; +use ReflectionProperty; +use stdClass; use Symfony\Bundle\FrameworkBundle\Test\KernelTestCase; use Symfony\Component\PasswordHasher\Hasher\UserPasswordHasherInterface; @@ -328,6 +331,59 @@ final class AuditListenerTest extends KernelTestCase ); } + /** + * Regression : quand un flush precedent a leve une exception avant + * d'atteindre postFlush, `$pendingLogs` reste rempli avec des changements + * jamais committes. Le flush suivant doit les ecraser, pas les fusionner — + * sinon audit_log contient des lignes pour des evenements qui n'ont pas + * eu lieu en base. + * + * Reproduction : on injecte manuellement une entree orpheline dans le + * listener (comme si un flush precedent l'avait capturee puis avait plante), + * on declenche un flush valide, et on verifie que l'orpheline n'apparait + * jamais dans audit_log. + */ + public function testOnFlushResetsStalePendingLogsFromFailedPreviousFlush(): void + { + /** @var AuditListener $listener */ + $listener = self::getContainer()->get(AuditListener::class); + + // Injecte une entree orpheline : comme si onFlush avait capture ce + // changement, puis que le flush avait plante avant postFlush. + $reflection = new ReflectionProperty($listener, 'pendingLogs'); + $reflection->setValue($listener, [[ + 'entity' => new stdClass(), + 'metadata' => null, + 'entityType' => 'test.StaleEntity', + 'action' => 'create', + 'changes' => ['fake' => ['old' => null, 'new' => 'stale']], + 'capturedId' => 'stale-id-'.$this->testRunTag, + ]]); + + // Flush valide qui DOIT re-initialiser pendingLogs avant de capturer + // ses propres changements. + $user = $this->makeUser(); + $this->em->persist($user); + $this->em->flush(); + $this->createdUserIds[] = $user->getId(); + + $staleRows = $this->auditConnection->fetchAllAssociative( + 'SELECT * FROM audit_log WHERE entity_type = :t', + ['t' => 'test.StaleEntity'], + ); + + self::assertCount( + 0, + $staleRows, + 'Une entree orpheline d\'un flush precedent ne doit pas fuiter dans audit_log.', + ); + + // Sanity : le vrai flush a quand meme bien ecrit sa propre ligne. + $userRows = $this->fetchAuditRows($user->getId()); + self::assertCount(1, $userRows); + self::assertSame('create', $userRows[0]['action']); + } + /** * @return list */