[java-oidc-common] branch main updated: Add basic metrics to dynamic metadata cache

Phil Smart philip.smart at jisc.ac.uk
Mon Nov 15 15:33:16 UTC 2021


This is an automated email from the git hooks/post-receive script.

philsmart pushed a commit to branch main
in repository java-oidc-common.

View the commit online:
http://git.shibboleth.net/view/?p=java-oidc-common.git;a=commit;h=5d1d1ef84b058c543754e636e49deeb5731d3d56

The following commit(s) were added to refs/heads/main by this push:
     new 5d1d1ef  Add basic metrics to dynamic metadata cache
5d1d1ef is described below

commit 5d1d1ef84b058c543754e636e49deeb5731d3d56
Author: Phil Smart <philip.smart at jisc.ac.uk>
AuthorDate: Mon Nov 15 15:33:08 2021 +0000

    Add basic metrics to dynamic metadata cache
---
 .../metadata/cache/impl/AbstractMetadataCache.java |   8 +-
 .../cache/impl/BaseMetadataCacheBuilderSpec.java   |   2 -
 .../metadata/cache/impl/DynamicMetadataCache.java  | 193 +++++++++++++++++----
 .../impl/DynamicMetadataCacheBuilderSpec.java      |   3 +-
 .../impl/AbstractOIDCMetadataResolver.java         |   3 -
 5 files changed, 159 insertions(+), 50 deletions(-)

diff --git a/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/AbstractMetadataCache.java b/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/AbstractMetadataCache.java
index 3fe1a7b..3d84721 100644
--- a/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/AbstractMetadataCache.java
+++ b/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/AbstractMetadataCache.java
@@ -97,13 +97,8 @@ public abstract class AbstractMetadataCache<IdentifierType, MetadataType>
     @NonnullAfterInit private BiFunction<MetadataType, MetadataFilterContext , MetadataType> metadataFilterStrategy;
     
     /** A single threaded executor service for running background cache tasks.*/
-    @NonnullAfterInit private ScheduledExecutorService executorService;
+    @NonnullAfterInit private ScheduledExecutorService executorService;  
     
-    /** Are metrics enabled?.*/
-    //TODO not yet implemented
-    private boolean enableMetrics;
-    
-
     
     /** Whether we created our own schedular during object construction. */
     private boolean createOwnSchedular;
@@ -181,7 +176,6 @@ public abstract class AbstractMetadataCache<IdentifierType, MetadataType>
     }
     
     @Override protected void doDestroy() {
-        log.info("Shutting down cache '{}'",getLogPrefix());
         executorService.shutdown();
         super.doDestroy();
     }
diff --git a/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/BaseMetadataCacheBuilderSpec.java b/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/BaseMetadataCacheBuilderSpec.java
index 86f813d..bf5583f 100644
--- a/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/BaseMetadataCacheBuilderSpec.java
+++ b/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/BaseMetadataCacheBuilderSpec.java
@@ -18,7 +18,6 @@
 
 package net.shibboleth.oidc.metadata.cache.impl;
 
-import java.time.Duration;
 import java.util.List;
 import java.util.function.BiConsumer;
 import java.util.function.BiFunction;
@@ -71,7 +70,6 @@ public abstract class BaseMetadataCacheBuilderSpec<IdentifierType, MetadataType>
         refreshDelayFactor = 0.75f;         
         // create a default direct in/out filter
         metadataFilterStrategy = (metadata, context) -> metadata;  
-        //cacheId = "unknown";
 
     }
     
diff --git a/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/DynamicMetadataCache.java b/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/DynamicMetadataCache.java
index 98fcc55..7e1fb2b 100644
--- a/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/DynamicMetadataCache.java
+++ b/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/DynamicMetadataCache.java
@@ -33,9 +33,16 @@ import java.util.function.Function;
 import javax.annotation.Nonnull;
 import javax.annotation.Nullable;
 
+import org.opensaml.core.metrics.MetricsSupport;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
+import com.codahale.metrics.Gauge;
+import com.codahale.metrics.MetricRegistry;
+import com.codahale.metrics.RatioGauge;
+import com.codahale.metrics.Timer;
+import com.codahale.metrics.Timer.Context;
+
 import net.shibboleth.oidc.metadata.DynamicBackingStore;
 import net.shibboleth.oidc.metadata.MetadataManagementData;
 import net.shibboleth.oidc.metadata.cache.ExpirationTimeContext;
@@ -46,6 +53,7 @@ import net.shibboleth.utilities.java.support.annotation.constraint.NotEmpty;
 import net.shibboleth.utilities.java.support.component.ComponentInitializationException;
 import net.shibboleth.utilities.java.support.component.ComponentSupport;
 import net.shibboleth.utilities.java.support.logic.Constraint;
+import net.shibboleth.utilities.java.support.primitive.StringSupport;
 import net.shibboleth.utilities.java.support.resolver.CriteriaSet;
 
 /**
@@ -68,6 +76,18 @@ import net.shibboleth.utilities.java.support.resolver.CriteriaSet;
 public class DynamicMetadataCache<IdentifierType, MetadataType> 
                             extends AbstractMetadataCache<IdentifierType, MetadataType> {
     
+    /** Metric name for the timer for {@link #resolve(CriteriaSet)}. */
+    public static final String METRIC_TIMER_GET = "timer.get";
+    
+    /** Metric name for the gauge of the number of live entityIDs. */
+    public static final String METRIC_GAUGE_NUM_LIVE_INDEX_METADATA = "gauge.numLiveIndexedMetadata";
+    
+    /** Metric name for the timer for {@link #fetch(MetadataManagementData, Object, CriteriaSet)}. */
+    public static final String METRIC_TIMER_FETCH_FROM_ORIGIN_SOURCE = "timer.fetchFromOriginSource";
+    
+    /** Metric name for the ratio gauge of fetches to resolve requests. */
+    public static final String METRIC_RATIOGAUGE_FETCH_TO_GET = "ratioGauge.fetchToGet";
+    
     /** Class logger. */
     private final Logger log = LoggerFactory.getLogger(DynamicMetadataCache.class);
     
@@ -98,6 +118,21 @@ public class DynamicMetadataCache<IdentifierType, MetadataType>
     
     /** Mapping function to use when creating new metadata management data.*/
     @Nonnull private final Function<IdentifierType, MetadataManagementData<IdentifierType>> mgmtMappingFunction;
+
+    /** Base name for Metrics instrumentation names. */
+    @NonnullAfterInit private String metricsBaseName;
+    
+    /** Metrics Timer for {@link #get(CriteriaSet)}. */
+    @Nullable private Timer timerGet;
+    
+    /** Metrics Timer for {@link #fetch(MetadataManagementData, Object, CriteriaSet)}. */
+    @Nullable private Timer timerFetchFromSource;
+    
+    /** Metrics RatioGauge for count of origin fetches to gets.*/
+    @Nullable private RatioGauge ratioGaugeFetchToGet;
+    
+    /** Metrics Gauge for the number of live indexed metadata.*/
+    @Nullable private Gauge<Integer> gaugeNumLiveIndexedMetadata;
     
     /** 
      * Constructor.
@@ -127,6 +162,7 @@ public class DynamicMetadataCache<IdentifierType, MetadataType>
         };
         
     }
+   
     
     /**
      *  Set the minimum cache duration for metadata.
@@ -164,7 +200,7 @@ public class DynamicMetadataCache<IdentifierType, MetadataType>
         ComponentSupport.ifInitializedThrowUnmodifiabledComponentException(this);
         ComponentSupport.ifDestroyedThrowDestroyedComponentException(this);
         
-        this.fetchStrategy = Constraint.isNotNull(strategy, "Dynamic Metadata fetch strategy can not be null");;
+        this.fetchStrategy = Constraint.isNotNull(strategy, "Dynamic Metadata fetch strategy can not be null");
     }
     
     /**
@@ -181,6 +217,26 @@ public class DynamicMetadataCache<IdentifierType, MetadataType>
         initialCleanupTaskDelay = delay;
         
     }
+    
+    /** {@inheritDoc} */
+    @Override
+    protected void doDestroy() {      
+        
+        if (ratioGaugeFetchToGet != null) {
+            MetricsSupport.remove(MetricRegistry.name(metricsBaseName, METRIC_RATIOGAUGE_FETCH_TO_GET), 
+                    ratioGaugeFetchToGet);
+        }
+        if (gaugeNumLiveIndexedMetadata != null) {
+            MetricsSupport.remove(MetricRegistry.name(metricsBaseName, METRIC_GAUGE_NUM_LIVE_INDEX_METADATA), 
+                    gaugeNumLiveIndexedMetadata);
+        }
+        ratioGaugeFetchToGet = null;
+        gaugeNumLiveIndexedMetadata = null;
+        timerFetchFromSource = null;
+        timerGet = null;
+        
+        super.doDestroy();
+    }
    
     
     /**
@@ -268,10 +324,60 @@ public class DynamicMetadataCache<IdentifierType, MetadataType>
             throw new ComponentInitializationException("Metadata fetching strategy can not be null");
         }
         
+        initializeMetricsInstrumentation();
+        
         getExecutorService().scheduleAtFixedRate(
                 errorHandlingWrapper(new ExpiredAndIdleMetadataCleanupTask()), initialCleanupTaskDelay.toMillis(), 
                 cleanupTaskInterval.toMillis(), TimeUnit.MILLISECONDS);
     }
+    
+    /**
+     * Initialize the Metrics-based instrumentation.
+     */
+    private void initializeMetricsInstrumentation() {
+       
+        // initialization is synchronized at the top level
+        if (metricsBaseName == null) {
+            setMetricsBaseName(MetricRegistry.name(this.getClass(), getId()));
+        }        
+        
+        final MetricRegistry metricRegistry = MetricsSupport.getMetricRegistry();
+        if (metricRegistry != null) {
+            timerGet = metricRegistry.timer(
+                    MetricRegistry.name(metricsBaseName, METRIC_TIMER_GET));  
+            timerFetchFromSource = metricRegistry.timer(
+                    MetricRegistry.name(metricsBaseName, METRIC_TIMER_FETCH_FROM_ORIGIN_SOURCE));
+            
+            // Note that these gauges must use the support method to register in a synchronized fashion,
+            // and also must store off the instances for later use in destroy.
+            ratioGaugeFetchToGet = MetricsSupport.register(
+                    MetricRegistry.name(metricsBaseName, METRIC_RATIOGAUGE_FETCH_TO_GET), 
+                    new RatioGauge() {
+                        protected Ratio getRatio() {
+                            return Ratio.of(timerFetchFromSource.getCount(), 
+                                    timerGet.getCount());
+                        }},
+                    true);
+            
+            gaugeNumLiveIndexedMetadata = MetricsSupport.register(
+                    MetricRegistry.name(metricsBaseName, METRIC_GAUGE_NUM_LIVE_INDEX_METADATA),
+                    () -> getBackingStore().getIndexedValues().keySet().size(),
+                    true);
+        }
+    }
+    
+    
+    /**
+     * Set the base name for Metrics instrumentation.
+     * 
+     * @param baseName the Metrics base name
+     */
+    public synchronized void setMetricsBaseName(@Nullable final String baseName) {
+        ComponentSupport.ifInitializedThrowUnmodifiabledComponentException(this);
+        ComponentSupport.ifDestroyedThrowDestroyedComponentException(this);
+        
+        metricsBaseName = StringSupport.trimOrNull(baseName);
+    }
         
     /**
      * {@inheritDoc}
@@ -291,33 +397,39 @@ public class DynamicMetadataCache<IdentifierType, MetadataType>
             throw new MetadataCacheException("Metadata cache has not been initialized");
         }
         
-        final IdentifierType identifier = getCriteriaToIdentifierStrategy().apply(criteria);
-        log.debug("{} Resolved criteria to identifier: {}", getLogPrefix(), identifier);
+        final Context contextResolve = MetricsSupport.startTimer(timerGet);
         
-        if (identifier != null) {       
-            //TODO check we can do this here, as another thread could change this concurrently?
-            final MetadataManagementData<IdentifierType> mgmtData = getBackingStore()
-                    .computeManagementDataIfAbsent(identifier, mgmtMappingFunction);
+        try {
+            final IdentifierType identifier = getCriteriaToIdentifierStrategy().apply(criteria);
+            log.debug("{} Resolved criteria to identifier: {}", getLogPrefix(), identifier);
             
-            // check metadata refresh is not needed before reading.
-            List<MetadataType> allMetadata = Collections.emptyList();
-            if (!shouldAttemptRefresh(mgmtData)) {
-                // TODO: Metadata that does not exist yet but its mgmtData has been created will attempt 
-                // a pointless read.
-                allMetadata = read(mgmtData, identifier);
-            }
-            if (allMetadata.isEmpty()) {
-                log.debug("Metadata for '{}' does not exist or is stale, attempting to fetch it", identifier);
-                fetch(mgmtData, identifier, criteria);
-                return read(mgmtData, identifier);
+            if (identifier != null) {       
+                //TODO check we can do this here, as another thread could change this concurrently?
+                final MetadataManagementData<IdentifierType> mgmtData = getBackingStore()
+                        .computeManagementDataIfAbsent(identifier, mgmtMappingFunction);
+                
+                // check metadata refresh is not needed before reading.
+                List<MetadataType> allMetadata = Collections.emptyList();
+                if (!shouldAttemptRefresh(mgmtData)) {
+                    // TODO: Metadata that does not exist yet but its mgmtData has been created will attempt 
+                    // a pointless read.
+                    allMetadata = read(mgmtData, identifier);
+                }
+                if (allMetadata.isEmpty()) {
+                    log.debug("Metadata for '{}' does not exist or is stale, attempting to fetch it", identifier);
+                    fetch(mgmtData, identifier, criteria);
+                    return read(mgmtData, identifier);
+                } else {
+                    log.debug("Metadata for '{}' found in cache", identifier);
+                    return allMetadata;
+                }   
             } else {
-                log.debug("Metadata for '{}' found in cache", identifier);
-                return allMetadata;
-            }   
-        } else {
-            //TODO: see SAML version, could resolve from criteria even if no identifier.
-            log.debug("Identifier not resolvable from criteria, can not fetch metadata");
-            return Collections.emptyList();
+                //TODO: see SAML version, could resolve from criteria even if no identifier.
+                log.debug("Identifier not resolvable from criteria, can not fetch metadata");
+                return Collections.emptyList();
+            }
+        } finally {
+            MetricsSupport.stopTimer(contextResolve);
         }
             
     }
@@ -351,7 +463,13 @@ public class DynamicMetadataCache<IdentifierType, MetadataType>
                 log.debug("{} Metadata for '{}' is stale and requires refreshing", getLogPrefix(), identifier);
             }
             
-            final MetadataType resolvedMetadata = fetchStrategy.apply(criteria);   
+            MetadataType resolvedMetadata = null;
+            final Context contextFetchFromSource = MetricsSupport.startTimer(timerFetchFromSource);
+            try {
+                resolvedMetadata = fetchStrategy.apply(criteria);   
+            } finally {
+                MetricsSupport.stopTimer(contextFetchFromSource);
+            }
             
             if (resolvedMetadata != null) {
                 storeNewMetadata(mgmtData, resolvedMetadata, identifier);
@@ -542,18 +660,19 @@ public class DynamicMetadataCache<IdentifierType, MetadataType>
             ids.addAll(store.getManagementDataIdentifiers());
             
             for (final IdentifierType identifier : ids) {
-                final MetadataManagementData<IdentifierType> mgmtData = store.getManagementData(identifier);
-                if (mgmtData != null) {
-                    final long stamp = mgmtData.getStampLock().writeLock();
-                    try {                                       
-                        if (isRemoveData(mgmtData, now, earliestValidLastAccessed)) {
-                            invalidate(identifier);
-                            store.removeManagementData(identifier);
-                        }                    
-                    } finally {
-                        mgmtData.getStampLock().unlock(stamp);
-                    }
+                final MetadataManagementData<IdentifierType> mgmtData = 
+                        store.computeManagementDataIfAbsent(identifier, mgmtMappingFunction);
+                
+                final long stamp = mgmtData.getStampLock().writeLock();
+                try {                                       
+                    if (isRemoveData(mgmtData, now, earliestValidLastAccessed)) {
+                        invalidate(identifier);
+                        store.removeManagementData(identifier);
+                    }                    
+                } finally {
+                    mgmtData.getStampLock().unlock(stamp);
                 }
+                
             }
             
         }
diff --git a/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/DynamicMetadataCacheBuilderSpec.java b/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/DynamicMetadataCacheBuilderSpec.java
index e6ac16b..bb460c8 100644
--- a/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/DynamicMetadataCacheBuilderSpec.java
+++ b/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/cache/impl/DynamicMetadataCacheBuilderSpec.java
@@ -20,7 +20,6 @@ package net.shibboleth.oidc.metadata.cache.impl;
 
 import java.time.Duration;
 import java.time.Instant;
-import java.util.function.BiFunction;
 import java.util.function.Function;
 
 import javax.annotation.Nonnull;
@@ -64,6 +63,7 @@ public class DynamicMetadataCacheBuilderSpec <IdentifierType, MetadataType>
     /** Strategy used to compute an expiration time. */
     @Nullable private Function<ExpirationTimeContext<MetadataType>, Instant> metadataExpirationTimeStrategy;
     
+    
     /** Constructor. */
     protected DynamicMetadataCacheBuilderSpec() {
         maxCacheDuration = Duration.ofHours(8);
@@ -74,6 +74,7 @@ public class DynamicMetadataCacheBuilderSpec <IdentifierType, MetadataType>
         removeIdleEntityData = true;
     }
     
+    
     /**
      *  Get the maximum cache duration for metadata.
      *  
diff --git a/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/impl/AbstractOIDCMetadataResolver.java b/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/impl/AbstractOIDCMetadataResolver.java
index 7607029..013935d 100644
--- a/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/impl/AbstractOIDCMetadataResolver.java
+++ b/oidc-common-metadata-impl/src/main/java/net/shibboleth/oidc/metadata/impl/AbstractOIDCMetadataResolver.java
@@ -126,15 +126,12 @@ public abstract class AbstractOIDCMetadataResolver<MetadataIdentifier, MetadataT
         ComponentSupport.ifNotInitializedThrowUninitializedComponentException(this);
         ComponentSupport.ifDestroyedThrowDestroyedComponentException(this);
                
-        //final Context contextResolve = MetricsSupport.startTimer(timerResolve);
         try {            
             final List<MetadataType> metadata = getCache().get(criteria);            
             return predicateFilterCandidates(metadata, criteria, false);
             
         } catch (final MetadataCacheException e) {
             throw new ResolverException(e);
-        } finally {
-            //MetricsSupport.stopTimer(contextResolve);
         } 
     }     
     

-- 
To stop receiving notification emails like this one, please contact
the administrator of this repository.


More information about the commits mailing list