From bcb1b5dd0fb53f712a6748448a8abc7077135d01 Mon Sep 17 00:00:00 2001 From: Daniel Radeau Date: Thu, 10 Sep 2026 11:59:10 +0200 Subject: [PATCH] =?UTF-8?q?bug=20#16842=20fix:=20import=20interminable,=20?= =?UTF-8?q?une=20attente=20d'1ms=20par=20objet=20import=C3=A9?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit doProgressLog terminait par un Thread.sleep(1) placé hors du test de niveau de log, ce dernier étant fait à l'intérieur de doProgressLogWithoutInterruption. L'attente s'exécutait donc à chaque appel, y compris quand le message était filtré et n'était affiché nulle part. Or ce doProgressLog est appelé au niveau OBJECTS dans les boucles chaudes de l'import, alors que ImportThread règle le niveau à OBJECTS_GROUP en mode normal: une attente par fichier extrait du zip, par DataObjectGroup, par BinaryDataObject, par PhysicalDataObject et par ArchiveUnit. Sur un SIP de 50 000 AU et 50 000 binaires cela fait environ 200 000 attentes, soit 4 mn sous Linux et jusqu'à 50 mn sous Windows où un sleep d'1ms dure réellement 15,6ms. Pendant tout ce temps les menus Traiter et Export restent grisés, puisque setContextLoaded n'est appelé que depuis ImportThread.done(), d'où l'impossibilité de vérifier la conformité SEDA, de vérifier la conformité à un profil et d'exporter le SIP dans la demi-heure suivant l'ouverture. - SEDALibProgressLogger: les trois Thread.sleep(1) sont remplacés par checkInterruption(), qui lève InterruptedException si le drapeau d'interruption est posé. La sémantique d'annulation est identique, Thread.sleep ne faisant rien d'autre sur interruption, mais le coût est nul. - SEDALibProgressLoggerTest: non-régression sur la durée des appels filtrés (20 000 appels sous 2s, contre 23s avant correctif) et sur la propagation de l'annulation par doProgressLog et doProgressLogIfStep. --- .../sedalib/utils/SEDALibProgressLogger.java | 22 +++- .../utils/SEDALibProgressLoggerTest.java | 115 ++++++++++++++++++ 2 files changed, 133 insertions(+), 4 deletions(-) create mode 100644 sedalib/src/test/java/fr/gouv/vitam/tools/sedalib/utils/SEDALibProgressLoggerTest.java diff --git a/sedalib/src/main/java/fr/gouv/vitam/tools/sedalib/utils/SEDALibProgressLogger.java b/sedalib/src/main/java/fr/gouv/vitam/tools/sedalib/utils/SEDALibProgressLogger.java index 78356c99..62d36213 100644 --- a/sedalib/src/main/java/fr/gouv/vitam/tools/sedalib/utils/SEDALibProgressLogger.java +++ b/sedalib/src/main/java/fr/gouv/vitam/tools/sedalib/utils/SEDALibProgressLogger.java @@ -321,7 +321,7 @@ public static void doProgressLogIfDebug(SEDALibProgressLogger spl, String log, T } /** - * Do progress log, and log with exception detail if any, and wait 1ms to allow interruption + * Do progress log, and log with exception detail if any, and check for interruption * * @param spl the SEDALib progress logger * @param level the level @@ -333,10 +333,24 @@ public static void doProgressLog(SEDALibProgressLogger spl, int level, String lo throws InterruptedException { if (spl != null) { doProgressLogWithoutInterruption(spl, level, log, e); - Thread.sleep(1); + checkInterruption(); } } + /** + * Check if the current thread has been interrupted, and if so throw the interruption. + *

+ * This is the interruption point offered to the callers of the progress log methods. It has to + * stay allocation and syscall free, as it's called once per imported object (per unzipped file, + * per DataObjectGroup, per BinaryDataObject, per ArchiveUnit...), even when the message is + * filtered out by the log level and displayed nowhere. + * + * @throws InterruptedException if the current thread has been interrupted + */ + private static void checkInterruption() throws InterruptedException { + if (Thread.interrupted()) throw new InterruptedException(); + } + /** * Do progress log if the counter is a step multiple. * @@ -356,7 +370,7 @@ public static void doProgressLogIfStep(SEDALibProgressLogger spl, int level, int (spl.progressLogFunc != null) && (level <= spl.progressFuncLogLevel) ) spl.progressLogFunc.doProgressLog(count, (count % spl.progressFuncStep == 0 ? "" : " * ") + log); spl.log(level, log); - Thread.sleep(1); + checkInterruption(); spl.previousStepEpochSeconds = nowEpochSeconds; return; } @@ -365,7 +379,7 @@ public static void doProgressLogIfStep(SEDALibProgressLogger spl, int level, int } if ((spl.progressLogFunc != null) && (count % spl.progressFuncStep) == 0) { spl.progressLogFunc.doProgressLog(count, log); - Thread.sleep(1); + checkInterruption(); } } } diff --git a/sedalib/src/test/java/fr/gouv/vitam/tools/sedalib/utils/SEDALibProgressLoggerTest.java b/sedalib/src/test/java/fr/gouv/vitam/tools/sedalib/utils/SEDALibProgressLoggerTest.java new file mode 100644 index 00000000..e7448553 --- /dev/null +++ b/sedalib/src/test/java/fr/gouv/vitam/tools/sedalib/utils/SEDALibProgressLoggerTest.java @@ -0,0 +1,115 @@ +/** + * Copyright French Prime minister Office/SGMAP/DINSIC/Vitam Program (2019-2022) + * and the signatories of the "VITAM - Accord du Contributeur" agreement. + * + * contact@programmevitam.fr + * + * This software is a computer program whose purpose is to provide + * tools for construction and manipulation of SIP (Submission + * Information Package) conform to the SEDA (Standard d’Échange + * de données pour l’Archivage) standard. + * + * This software is governed by the CeCILL-C license under French law and + * abiding by the rules of distribution of free software. You can use, + * modify and/ or redistribute the software under the terms of the CeCILL-C + * license as circulated by CEA, CNRS and INRIA at the following URL + * "http://www.cecill.info". + * + * As a counterpart to the access to the source code and rights to copy, + * modify and redistribute granted by the license, users are provided only + * with a limited warranty and the software's author, the holder of the + * economic rights, and the successive licensors have only limited + * liability. + * + * In this respect, the user's attention is drawn to the risks associated + * with loading, using, modifying and/or developing or reproducing the + * software by the user in light of its specific status of free software, + * that may mean that it is complicated to manipulate, and that also + * therefore means that it is reserved for developers and experienced + * professionals having in-depth computer knowledge. Users are therefore + * encouraged to load and test the software's suitability as regards their + * requirements in conditions enabling the security of their systems and/or + * data to be ensured and, more generally, to use and operate it in the + * same conditions as regards security. + * + * The fact that you are presently reading this means that you have had + * knowledge of the CeCILL-C license and that you accept its terms. + */ +package fr.gouv.vitam.tools.sedalib.utils; + +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.Test; + +import static fr.gouv.vitam.tools.sedalib.utils.SEDALibProgressLogger.OBJECTS; +import static fr.gouv.vitam.tools.sedalib.utils.SEDALibProgressLogger.OBJECTS_GROUP; +import static org.junit.jupiter.api.Assertions.*; + +class SEDALibProgressLoggerTest { + + private static final int FILTERED_OUT_CALLS = 20000; + + @AfterEach + void clearInterruptedFlag() { + Thread.interrupted(); + } + + /** + * Non regression on the import duration: doProgressLog used to end with a Thread.sleep(1) placed + * outside of the log level test, so every unzipped file, DataObjectGroup, BinaryDataObject and + * ArchiveUnit cost at least one sleep even when the message was filtered out and displayed + * nowhere. On Windows, where a 1ms sleep really lasts up to 15.6ms, that alone turned the import + * of a large SIP into a half hour of pure sleeping, during which the Traiter and Export menus + * stayed greyed out. + */ + @Test + void shouldNotWaitOnMessagesFilteredOutByLogLevel() throws InterruptedException { + SEDALibProgressLogger spl = new SEDALibProgressLogger(null, OBJECTS_GROUP); + + long start = System.nanoTime(); + for (int i = 0; i < FILTERED_OUT_CALLS; i++) { + SEDALibProgressLogger.doProgressLog(spl, OBJECTS, "sedalib: objet [" + i + "] importé", null); + } + long durationMs = (System.nanoTime() - start) / 1_000_000; + + // one sleep per call would be at least 20s here, and around 5mn on Windows + assertTrue( + durationMs < 2000, + FILTERED_OUT_CALLS + " appels filtrés ont pris " + durationMs + "ms, un délai est réapparu par appel" + ); + } + + @Test + void shouldThrowWhenThreadIsInterrupted() { + SEDALibProgressLogger spl = new SEDALibProgressLogger(null, OBJECTS_GROUP); + + Thread.currentThread().interrupt(); + + assertThrows( + InterruptedException.class, + () -> SEDALibProgressLogger.doProgressLog(spl, OBJECTS, "sedalib: objet importé", null) + ); + assertFalse(Thread.currentThread().isInterrupted(), "le drapeau d'interruption doit avoir été consommé"); + } + + @Test + void shouldThrowFromStepLogWhenThreadIsInterrupted() { + SEDALibProgressLogger spl = new SEDALibProgressLogger(null, OBJECTS_GROUP, (count, log) -> {}, 1); + + Thread.currentThread().interrupt(); + + assertThrows( + InterruptedException.class, + () -> SEDALibProgressLogger.doProgressLogIfStep(spl, OBJECTS_GROUP, 1, "1 fichier extrait") + ); + assertFalse(Thread.currentThread().isInterrupted(), "le drapeau d'interruption doit avoir été consommé"); + } + + @Test + void shouldNotThrowWhenThreadIsNotInterrupted() { + SEDALibProgressLogger spl = new SEDALibProgressLogger(null, OBJECTS_GROUP); + + assertDoesNotThrow( + () -> SEDALibProgressLogger.doProgressLog(spl, OBJECTS_GROUP, "sedalib: import terminé", null) + ); + } +}