This is an automated email from the ASF dual-hosted git repository. desruisseaux pushed a commit to branch geoapi-4.0 in repository https://gitbox.apache.org/repos/asf/sis.git
commit 24e3b713dcd6eb2d9cfa16e5c40045fbdd7ca4a9 Author: Martin Desruisseaux <martin.desruisse...@geomatys.com> AuthorDate: Wed Jan 12 19:07:21 2022 +0100 Reduce the log levels (from FINE to FINER) of CRS created as a result of scanning the database in search for a CRS matching criteria. --- .../org/apache/sis/metadata/MetadataStandard.java | 4 +-- .../org/apache/sis/metadata/MetadataVisitor.java | 4 +-- .../org/apache/sis/metadata/TreeTableView.java | 4 +-- .../org/apache/sis/metadata/sql/Dispatcher.java | 4 +-- .../factory/ConcurrentAuthorityFactory.java | 15 ++++------- .../referencing/factory/GeodeticObjectFactory.java | 30 +++++++++++++--------- .../factory/IdentifiedObjectFinder.java | 28 ++++++++++++-------- .../referencing/factory/sql/EPSGCodeFinder.java | 9 ++++--- .../referencing/factory/sql/EPSGDataAccess.java | 10 +++----- .../operation/AbstractCoordinateOperation.java | 2 +- .../operation/CoordinateOperationRegistry.java | 4 +-- .../org/apache/sis/internal/system/Semaphores.java | 26 ++++++++++++++++--- .../apache/sis/internal/system/package-info.java | 2 +- src/main/config/logging.properties | 8 +++--- 14 files changed, 84 insertions(+), 66 deletions(-) diff --git a/core/sis-metadata/src/main/java/org/apache/sis/metadata/MetadataStandard.java b/core/sis-metadata/src/main/java/org/apache/sis/metadata/MetadataStandard.java index 5833d4f..770b816 100644 --- a/core/sis-metadata/src/main/java/org/apache/sis/metadata/MetadataStandard.java +++ b/core/sis-metadata/src/main/java/org/apache/sis/metadata/MetadataStandard.java @@ -1025,9 +1025,7 @@ public class MetadataStandard implements Serializable { return accessor.equals(metadata1, metadata2, mode); } finally { inProgress.remove(pair); - if (!allowNull) { - Semaphores.clear(Semaphores.NULL_COLLECTION); - } + Semaphores.clear(Semaphores.NULL_COLLECTION, allowNull); } } else { /* diff --git a/core/sis-metadata/src/main/java/org/apache/sis/metadata/MetadataVisitor.java b/core/sis-metadata/src/main/java/org/apache/sis/metadata/MetadataVisitor.java index d966c3b..d337c46 100644 --- a/core/sis-metadata/src/main/java/org/apache/sis/metadata/MetadataVisitor.java +++ b/core/sis-metadata/src/main/java/org/apache/sis/metadata/MetadataVisitor.java @@ -203,9 +203,7 @@ abstract class MetadataVisitor<R> { * We are back to the root metadata (i.e. we finished walking through all children). * Clear thread local variables, which should restore them to their initial value. */ - if (!allowNull) { - Semaphores.clear(Semaphores.NULL_COLLECTION); - } + Semaphores.clear(Semaphores.NULL_COLLECTION, allowNull); final ThreadLocal<? extends MetadataVisitor<?>> creator = creator(); if (creator != null) creator.remove(); } diff --git a/core/sis-metadata/src/main/java/org/apache/sis/metadata/TreeTableView.java b/core/sis-metadata/src/main/java/org/apache/sis/metadata/TreeTableView.java index 4ed4ecf..ef93339 100644 --- a/core/sis-metadata/src/main/java/org/apache/sis/metadata/TreeTableView.java +++ b/core/sis-metadata/src/main/java/org/apache/sis/metadata/TreeTableView.java @@ -143,9 +143,7 @@ final class TreeTableView implements TreeTable, TreeFormatCustomization, Seriali return MetadataFormat.INSTANCE.format(this); } } finally { - if (!allowNull) { - Semaphores.clear(Semaphores.NULL_COLLECTION); - } + Semaphores.clear(Semaphores.NULL_COLLECTION, allowNull); } } diff --git a/core/sis-metadata/src/main/java/org/apache/sis/metadata/sql/Dispatcher.java b/core/sis-metadata/src/main/java/org/apache/sis/metadata/sql/Dispatcher.java index 9b6156b..9eb83a9 100644 --- a/core/sis-metadata/src/main/java/org/apache/sis/metadata/sql/Dispatcher.java +++ b/core/sis-metadata/src/main/java/org/apache/sis/metadata/sql/Dispatcher.java @@ -278,9 +278,7 @@ final class Dispatcher implements InvocationHandler { } } } finally { - if (!allowNull) { - Semaphores.clear(Semaphores.NULL_COLLECTION); - } + Semaphores.clear(Semaphores.NULL_COLLECTION, allowNull); } } if (value == null) { diff --git a/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/ConcurrentAuthorityFactory.java b/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/ConcurrentAuthorityFactory.java index 358fc38..41c0c76 100644 --- a/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/ConcurrentAuthorityFactory.java +++ b/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/ConcurrentAuthorityFactory.java @@ -95,7 +95,7 @@ import org.apache.sis.util.resources.Messages; * Subclasses should select the interfaces that they choose to implement. * * @author Martin Desruisseaux (IRD, Geomatys) - * @version 1.1 + * @version 1.2 * * @param <DAO> the type of factory used as Data Access Object (DAO). * @@ -106,13 +106,6 @@ public abstract class ConcurrentAuthorityFactory<DAO extends GeodeticAuthorityFa extends GeodeticAuthorityFactory implements AutoCloseable { /** - * Duration of data access operations that should be logged, in nanoseconds. - * Any operation that take longer than this amount of time to execute will have a message logged. - * The log level depends on the execution duration as specified in {@link PerformanceLevel}. - */ - private static final long DURATION_FOR_LOGGING = 10_000_000L; // 10 milliseconds. - - /** * Sentinel value when {@link #authority} can not be determined because the data access object * can not be constructed. */ @@ -474,9 +467,11 @@ public abstract class ConcurrentAuthorityFactory<DAO extends GeodeticAuthorityFa time = usage.timestamp - time; } /* - * Log only events that take longer than the threshold (e.g. 10 milliseconds). + * Log the event. Note: there is no need to check for `Semaphores.FINER_OBJECT_CREATION_LOGS` + * because this method is not invoked, or is invoked with `type = null`, during execution of + * `IdentifiedObjectFinder` seach operations. */ - if (time >= DURATION_FOR_LOGGING && type != null) { + if (type != null) { if (caller == null) { caller = "create".concat(type.getSimpleName()); } diff --git a/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/GeodeticObjectFactory.java b/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/GeodeticObjectFactory.java index 68ce130..45e1e03 100644 --- a/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/GeodeticObjectFactory.java +++ b/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/GeodeticObjectFactory.java @@ -54,6 +54,7 @@ import org.apache.sis.internal.referencing.ReferencingFactoryContainer; import org.apache.sis.internal.referencing.MergedProperties; import org.apache.sis.internal.system.DefaultFactories; import org.apache.sis.internal.system.Loggers; +import org.apache.sis.internal.system.Semaphores; import org.apache.sis.internal.util.CollectionsExt; import org.apache.sis.util.collection.WeakHashSet; import org.apache.sis.util.iso.AbstractFactory; @@ -192,7 +193,7 @@ import org.apache.sis.xml.XML; * @author Martin Desruisseaux (IRD, Geomatys) * @author Guilhem Legal (Geomatys) * @author Johann Sorel (Geomatys) - * @version 0.8 + * @version 1.2 * @since 0.6 * @module */ @@ -312,20 +313,25 @@ public class GeodeticObjectFactory extends AbstractFactory implements CRSFactory /** * Returns a unique instance of the given object. If this method recycles an existing object, * then the existing instance is returned silently. Otherwise this method logs a message at - * {@link Level#FINE} telling that a new object has been created. + * {@link Level#FINE} or {@link Level#FINER} telling that a new object has been created. + * The finer level is used if the object has been creating during an operation that creates + * a lot of candidates in search for a CRS matching some criterion. */ private <T extends AbstractIdentifiedObject> T unique(final String caller, final T object) { final T c = pool.unique(object); - if (c == object && LOGGER.isLoggable(Level.FINE)) { - final String id = IdentifiedObjects.toString(IdentifiedObjects.getIdentifier(c, null)); - final LogRecord record = Messages.getResources(null).getLogRecord(Level.FINE, - (id != null) ? Messages.Keys.CreatedIdentifiedObject_3 - : Messages.Keys.CreatedNamedObject_2, - c.getInterface(), c.getName().getCode(), id); - record.setSourceClassName(GeodeticObjectFactory.class.getCanonicalName()); - record.setSourceMethodName(caller); - record.setLoggerName(LOGGER.getName()); - LOGGER.log(record); + if (c == object) { + final Level level = Semaphores.query(Semaphores.FINER_OBJECT_CREATION_LOGS) ? Level.FINER : Level.FINE; + if (LOGGER.isLoggable(level)) { + final String id = IdentifiedObjects.toString(IdentifiedObjects.getIdentifier(c, null)); + final LogRecord record = Messages.getResources(null).getLogRecord(level, + (id != null) ? Messages.Keys.CreatedIdentifiedObject_3 + : Messages.Keys.CreatedNamedObject_2, + c.getInterface(), c.getName().getCode(), id); + record.setSourceClassName(GeodeticObjectFactory.class.getCanonicalName()); + record.setSourceMethodName(caller); + record.setLoggerName(LOGGER.getName()); + LOGGER.log(record); + } } return c; } diff --git a/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/IdentifiedObjectFinder.java b/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/IdentifiedObjectFinder.java index e97de92..da4391a 100644 --- a/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/IdentifiedObjectFinder.java +++ b/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/IdentifiedObjectFinder.java @@ -31,6 +31,7 @@ import org.apache.sis.referencing.AbstractIdentifiedObject; import org.apache.sis.referencing.IdentifiedObjects; import org.apache.sis.internal.util.Constants; import org.apache.sis.internal.system.Loggers; +import org.apache.sis.internal.system.Semaphores; import org.apache.sis.util.collection.BackingStoreException; import org.apache.sis.util.logging.Logging; import org.apache.sis.util.ArgumentChecks; @@ -58,7 +59,7 @@ import org.apache.sis.util.Utilities; * is thread-safe. If concurrent searches are desired, then a new instance should be created for each thread. * * @author Martin Desruisseaux (IRD, Geomatys) - * @version 1.1 + * @version 1.2 * * @see GeodeticAuthorityFactory#newIdentifiedObjectFinder() * @see IdentifiedObjects#newFinder(String) @@ -512,17 +513,22 @@ public class IdentifiedObjectFinder { */ Set<IdentifiedObject> createFromCodes(final IdentifiedObject object) throws FactoryException { final Set<IdentifiedObject> result = new LinkedHashSet<>(); // We need to preserve order. - for (final String code : getCodeCandidates(object)) { - final IdentifiedObject candidate; - try { - candidate = create(code); - } catch (FactoryException e) { - exceptionOccurred(e); - continue; - } - if (match(candidate, object)) { - result.add(candidate); + final boolean finer = Semaphores.queryAndSet(Semaphores.FINER_OBJECT_CREATION_LOGS); + try { + for (final String code : getCodeCandidates(object)) { + final IdentifiedObject candidate; + try { + candidate = create(code); + } catch (FactoryException e) { + exceptionOccurred(e); + continue; + } + if (match(candidate, object)) { + result.add(candidate); + } } + } finally { + Semaphores.clear(Semaphores.FINER_OBJECT_CREATION_LOGS, finer); } return result; } diff --git a/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/sql/EPSGCodeFinder.java b/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/sql/EPSGCodeFinder.java index 43245e5..f3bbb24 100644 --- a/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/sql/EPSGCodeFinder.java +++ b/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/sql/EPSGCodeFinder.java @@ -296,9 +296,9 @@ crs: if (isInstance(CoordinateReferenceSystem.class, object)) { table = TableInfo.CRS; if (isInstance(CompoundCRS.class, object)) { final List<CoordinateReferenceSystem> components = ((CompoundCRS) object).getComponents(); - if (components != null) switch (components.size()) { // Paranoiac check. - case 1: return getCodeCandidates(components.get(0)); // Should not happen. - case 2: { + if (components != null) { // Paranoiac check. + final int n = components.size(); + if (n == 2) { filters = new Condition[2]; for (int i=0; i<=1; i++) { if ((filters[i] = dependencies((i==0) ? "CMPD_HORIZCRS_CODE" : "CMPD_VERTCRS_CODE", @@ -309,6 +309,9 @@ crs: if (isInstance(CoordinateReferenceSystem.class, object)) { } break crs; } + if (n == 1) { // Should not happen. + return getCodeCandidates(components.get(0)); + } } } /* diff --git a/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/sql/EPSGDataAccess.java b/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/sql/EPSGDataAccess.java index 47552d8..63b4c88 100644 --- a/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/sql/EPSGDataAccess.java +++ b/core/sis-referencing/src/main/java/org/apache/sis/referencing/factory/sql/EPSGDataAccess.java @@ -1449,10 +1449,10 @@ codes: for (int i=0; i<codes.length; i++) { throw (NoSuchAuthorityCodeException) noSuchAuthorityCode(Projection.class, opCode).initCause(e); } final CoordinateReferenceSystem baseCRS; - final boolean resumeParamChecks; + final boolean suspendParamChecks; if (!deprecated) { baseCRS = owner.createCoordinateReferenceSystem(geoCode); - resumeParamChecks = false; + suspendParamChecks = true; } else { /* * If the ProjectedCRS is deprecated, one reason among others may be that it uses one of @@ -1480,7 +1480,7 @@ codes: for (int i=0; i<codes.length; i++) { * If and only if we are creating a deprecated CRS, temporarily suspend the parameter * checks. */ - resumeParamChecks = !Semaphores.queryAndSet(Semaphores.SUSPEND_PARAMETER_CHECK); + suspendParamChecks = Semaphores.queryAndSet(Semaphores.SUSPEND_PARAMETER_CHECK); // Try block must be immediately after above line (do not insert any code between). } try { @@ -1497,9 +1497,7 @@ codes: for (int i=0; i<codes.length; i++) { crs = crsFactory.createDerivedCRS(properties, baseCRS, op, cs); } } finally { - if (resumeParamChecks) { - Semaphores.clear(Semaphores.SUSPEND_PARAMETER_CHECK); - } + Semaphores.clear(Semaphores.SUSPEND_PARAMETER_CHECK, suspendParamChecks); } } finally { endOfRecursivity(ProjectedCRS.class, epsg); diff --git a/core/sis-referencing/src/main/java/org/apache/sis/referencing/operation/AbstractCoordinateOperation.java b/core/sis-referencing/src/main/java/org/apache/sis/referencing/operation/AbstractCoordinateOperation.java index 3e1fa65..80eaa44 100644 --- a/core/sis-referencing/src/main/java/org/apache/sis/referencing/operation/AbstractCoordinateOperation.java +++ b/core/sis-referencing/src/main/java/org/apache/sis/referencing/operation/AbstractCoordinateOperation.java @@ -903,7 +903,7 @@ check: for (int isTarget=0; ; isTarget++) { // 0 == source check; 1 this.getTargetCRS().getCoordinateSystem())); tr2 = MathTransforms.concatenate(before, tr2, after); } catch (IncommensurableException | RuntimeException e) { - Logging.recoverableException(Logging.getLogger(Loggers.COORDINATE_OPERATION), + Logging.ignorableException(Logging.getLogger(Loggers.COORDINATE_OPERATION), AbstractCoordinateOperation.class, "equals", e); } if (deepEquals(tr1, tr2, mode)) return true; diff --git a/core/sis-referencing/src/main/java/org/apache/sis/referencing/operation/CoordinateOperationRegistry.java b/core/sis-referencing/src/main/java/org/apache/sis/referencing/operation/CoordinateOperationRegistry.java index f470f78..6fa5c55 100644 --- a/core/sis-referencing/src/main/java/org/apache/sis/referencing/operation/CoordinateOperationRegistry.java +++ b/core/sis-referencing/src/main/java/org/apache/sis/referencing/operation/CoordinateOperationRegistry.java @@ -564,9 +564,7 @@ class CoordinateOperationRegistry { throw exception.unwrapOrRethrow(FactoryException.class); } } finally { - if (!mdOnly) { - Semaphores.clear(Semaphores.METADATA_ONLY); - } + Semaphores.clear(Semaphores.METADATA_ONLY, mdOnly); } } } diff --git a/core/sis-utility/src/main/java/org/apache/sis/internal/system/Semaphores.java b/core/sis-utility/src/main/java/org/apache/sis/internal/system/Semaphores.java index 86f82c6..26f1940 100644 --- a/core/sis-utility/src/main/java/org/apache/sis/internal/system/Semaphores.java +++ b/core/sis-utility/src/main/java/org/apache/sis/internal/system/Semaphores.java @@ -25,7 +25,7 @@ import org.apache.sis.util.Workaround; * a {@code try ... finally} block. * * @author Martin Desruisseaux (Geomatys) - * @version 0.8 + * @version 1.2 * @since 0.5 * @module */ @@ -57,8 +57,8 @@ public final class Semaphores { /** * A flag to indicate that {@link org.apache.sis.referencing.operation.AbstractCoordinateOperation} - * is querying parameters of a {@code MathTransform} enclosed in the operation. This is often in the - * intent to format WKT of a {@code "ProjectedCRS"} element. + * is querying parameters of a {@code MathTransform} enclosed in the operation. This is often at the + * time of formatting the WKT of a {@code "ProjectedCRS"} element. */ public static final int ENCLOSED_IN_OPERATION = 8; @@ -74,6 +74,13 @@ public final class Semaphores { public static final int SUSPEND_PARAMETER_CHECK = 16; /** + * A flag to indicate that a finer logging level should be used for reporting geodetic object creations. + * This flag is used during operations that potentially create a large amount of CRS, for example when + * trying many CRS candidates in search for a CRS compliant with some criteria. + */ + public static final int FINER_OBJECT_CREATION_LOGS = 32; + + /** * The flags per running thread. */ private static final ThreadLocal<Semaphores> FLAGS = new ThreadLocal<>(); @@ -128,4 +135,17 @@ public final class Semaphores { s.flags &= ~flag; } } + + /** + * Clears the given flag only if it was previously cleared. + * This is a convenience method for a common pattern with {@code try … finally} blocks. + * + * @param flag one of {@link #CONVERSION_AND_CRS}, {@link #ENCLOSED_IN_OPERATION} or other constants. + * @param previous value returned by {@link #queryAndSet(int)}. + */ + public static void clear(final int flag, final boolean previous) { + if (!previous) { + clear(flag); + } + } } diff --git a/core/sis-utility/src/main/java/org/apache/sis/internal/system/package-info.java b/core/sis-utility/src/main/java/org/apache/sis/internal/system/package-info.java index 998357c..489c4ac 100644 --- a/core/sis-utility/src/main/java/org/apache/sis/internal/system/package-info.java +++ b/core/sis-utility/src/main/java/org/apache/sis/internal/system/package-info.java @@ -24,7 +24,7 @@ * may change in incompatible ways in any future version without notice. * * @author Martin Desruisseaux (Geomatys) - * @version 1.1 + * @version 1.2 * @since 0.3 * @module */ diff --git a/src/main/config/logging.properties b/src/main/config/logging.properties index 603ea0d..e8c8ef7 100644 --- a/src/main/config/logging.properties +++ b/src/main/config/logging.properties @@ -20,11 +20,11 @@ handlers = java.util.logging.FileHandler, java.util.logging.ConsoleHandler .level = CONFIG # Enable debugging information for Apache SIS packages. -org.apache.sis.level = FINE +org.apache.sis.level = FINER -# Set the message that are printed on the console to FINE and above. -# FINE provides debugging information normally hidden in production. -java.util.logging.ConsoleHandler.level = FINE +# Set the message that are printed on the console to FINER and above. +# FINER provides debugging information normally hidden in production. +java.util.logging.ConsoleHandler.level = FINER # MonolineFormatter is optional and specific to Apache SIS. Its default configuration does # not show source class and method names. The second line below configures that formatter