From d5127d08328a5cda5f4132d37bdc3005ded6c774 Mon Sep 17 00:00:00 2001 From: Bastien Date: Thu, 13 Aug 2026 22:29:06 +0200 Subject: [PATCH] =?UTF-8?q?[Bug]=20-=20Rend=20visibles=20les=20=C3=A9checs?= =?UTF-8?q?=20op=C3=A9rationnels=20de=20l'import=20RPPS?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Trois défauts constatés en conditions réelles lors de la première exécution complète sur staging. Une exécution bloquée par le verrou se présentait comme un succès. Après qu'une tâche a été tuée, MySQL n'avait pas encore libéré son verrou nommé : l'exécution suivante a affiché « skipping this run » et s'est terminée avec le code 0. ECS enregistrait donc une réussite, rien ne remontait à Sentry, et le référentiel pouvait rester des semaines sans import — précisément ce que cette commande est censée empêcher. Le code de sortie est désormais un échec, et le message indique la piste du verrou résiduel avec la requête à exécuter pour le vérifier. Le mode debug faisait échouer l'import par épuisement mémoire. Avec la barre de debug active, doctrine-bundle conserve chaque requête exécutée, accompagnée de sa pile d'appels, pour toute la durée du processus. À environ cinq requêtes par ligne, la limite de 2 Gio du conteneur est atteinte vers 250 000 lignes et la tâche est tuée sans message exploitable. APP_ENV valant « staging » sur la tâche planifiée, le debug est actif sauf désactivation explicite, et le setSQLLogger(null) présent ne protège de rien : c'est le mécanisme DBAL 2, la collecte passant désormais par un middleware. La commande refuse maintenant de démarrer, en une seconde plutôt qu'en vingt minutes. La progression était trop espacée pour distinguer une exécution vivante d'une exécution bloquée. Une ligne toutes les 50 000 lignes laissait plusieurs minutes de silence. Passage à 10 000, soit environ 227 lignes par exécution — sans commune mesure avec les 40 000 d'origine. Vérifié : sans --no-debug la commande refuse immédiatement et l'erreur est journalisée en critical ; avec --no-debug elle démarre normalement ; verrou tenu par une autre session, la commande sort en code 1 avec le message de diagnostic. Co-Authored-By: Claude Opus 5 (1M context) --- src/Command/RppsImport.php | 28 ++++++++++++++++++++++++++-- src/Service/FileParserService.php | 7 ++++--- 2 files changed, 30 insertions(+), 5 deletions(-) diff --git a/src/Command/RppsImport.php b/src/Command/RppsImport.php index 597d290..481b9ba 100755 --- a/src/Command/RppsImport.php +++ b/src/Command/RppsImport.php @@ -7,11 +7,13 @@ use Doctrine\DBAL\Platforms\AbstractMySQLPlatform; use Doctrine\ORM\EntityManagerInterface; use Psr\Log\LoggerInterface; +use RuntimeException; use Symfony\Component\Console\Attribute\AsCommand; use Symfony\Component\Console\Command\Command; use Symfony\Component\Console\Input\InputInterface; use Symfony\Component\Console\Input\InputOption; use Symfony\Component\Console\Output\OutputInterface; +use Symfony\Component\DependencyInjection\Attribute\Autowire; use Throwable; #[AsCommand( @@ -34,6 +36,8 @@ class RppsImport extends Command public function __construct( protected readonly RPPSService $rppsService, protected readonly EntityManagerInterface $em, + #[Autowire('%kernel.debug%')] + private readonly bool $debug = false, private readonly ?LoggerInterface $logger = null, ) { parent::__construct(); @@ -85,12 +89,32 @@ protected function execute(InputInterface $input, OutputInterface $output): int $this->rppsService->setOutput($output); $this->rppsService->setMaxPurgeRatio((float) $input->getOption('max-purge-ratio')); + // With the debug toolbar active, doctrine-bundle keeps every executed query -- with a + // backtrace -- for the whole process. At roughly five queries per row that exhausts the + // container a few hundred thousand rows in, and the task is SIGKILLed with no usable + // error. Note the setSQLLogger(null) below does not prevent this: it is the DBAL 2 + // mechanism, and collection now happens through a middleware. APP_ENV is `staging` on + // the scheduled task, so debug is on unless it is explicitly turned off. + if ($this->debug) { + throw new RuntimeException( + 'Refusing to run with debug enabled: query collection would exhaust memory ' + . 'long before the import completes. Re-run with --no-debug.' + ); + } + if (!$this->acquireLock()) { + // Deliberately a failure, not a success. A scheduled run that silently does nothing + // is the exact outcome this command exists to avoid: ECS would record a clean exit + // and nothing would reach Sentry, so the register could go weeks without an import. + // This also covers a lock left behind by a killed task -- MySQL frees it only once + // it notices the dead connection, which can take longer than the gap between runs. $output->writeln( - 'Another RPPS import is already running, skipping this run.' + 'Another RPPS import holds the lock, so this run did nothing. If no import ' + . 'is actually running, a previous one was killed and the lock has not been ' + . "released yet: check SELECT IS_USED_LOCK('rpps_import')." ); - return Command::SUCCESS; + return Command::FAILURE; } try { diff --git a/src/Service/FileParserService.php b/src/Service/FileParserService.php index 400646d..07267f7 100755 --- a/src/Service/FileParserService.php +++ b/src/Service/FileParserService.php @@ -75,9 +75,10 @@ protected function processFile( // of the consecutive rows belonging to the same practitioner. $batchSize = 500; - // Progress every 50k rows rather than every batch: at one line per batch a full run - // emitted ~40k lines, each of which is a CloudWatch PutLogEvents call on ECS. - $progressEvery = 50000; + // Progress every 10k rows: one line per batch meant ~40k lines per run, but 50k was + // too sparse to tell a working import from a hung one -- minutes of silence either way. + // At ~600 rows/s this is a heartbeat every ~17s, and ~227 lines for a full run. + $progressEvery = 10000; $lineCount = $this->fileProcessor->getLinesCount($file);