Log the slow suppliers (dev mode) and catch exceptions

api/src/org/labkey/api/ApiModule.java

@@ -41,6 +41,7 @@
 import org.labkey.api.cache.BlockingCache;
 import org.labkey.api.cache.CacheManager;
 import org.labkey.api.cache.ContainerKeySimpleCache;
+import org.labkey.api.cache.NightlyRecalculatingSuppliers;
 import org.labkey.api.cache.SimpleKeyMappingCache;
 import org.labkey.api.cache.UserKeySimpleCache;
 import org.labkey.api.collections.ArrayListMap;
@@ -300,6 +301,7 @@ protected Collection<? extends WebPartFactory> createWebPartFactories()
     protected void doStartup(ModuleContext moduleContext)
     {
         SystemMaintenance.addTask(new ApiKeyMaintenanceTask());
+        SystemMaintenance.addTask(new NightlyRecalculatingSuppliers.RecalculationMaintenanceTask());
         AuthenticationManager.registerMetricsProvider();
         ContentSecurityPolicyFilter.registerMetricsProvider();
         ApiKeyManager.get().handleStartupProperties();

api/src/org/labkey/api/cache/BlockingCache.java

@@ -160,7 +160,7 @@ public V get(@NotNull K key, @Nullable Object argument, CacheLoader<K, V> loader
                     throw new IllegalStateException("cache loader was not provided");
 
                 V value = load(key, argument, loader);
-                CacheManager.validate("BlockingCache over \"" + _cache + "\" cache", value);
+                CacheManager.validate("BlockingCache over \"" + _cache + "\" cache", key, value);
 
                 synchronized (w.getLockObject())
                 {

api/src/org/labkey/api/cache/CacheManager.java

@@ -182,16 +182,16 @@ public static void shutdown()
     private static final Set<Class<?>> CLASSES = new HashSet<>();
 
     // Validate a cached value. Log errors for mutable collections/arrays and for values holding Container or User objects.
-    public static <V> void validate(String debugName, @Nullable V value)
+    public static <K, V> void validate(String debugName, K key, @Nullable V value)
     {
         if (value instanceof Wrapper<?>)
             return;
 
-        String description = CollectionUtils.getModifiableCollectionMapOrArrayType(value);
+        String valueDescription = CollectionUtils.getModifiableCollectionMapOrArrayType(value);
 
-        if (null != description)
+        if (null != valueDescription)
         {
-            LOG.error("{} attempted to cache {}, which could be mutated by callers!", debugName, description);
+            LOG.error("{} attempted to cache {}, which could be mutated by callers, at key {}", debugName, valueDescription, key);
         }
 
         // Flag values that hold a Container or User object

api/src/org/labkey/api/cache/CacheWrapper.java

@@ -66,7 +66,7 @@ public void put(@NotNull K key, V value)
                 value = _nullMarker;
 
             _cache.put(key, value);
-            trackPut(value);
+            trackPut(key, value);
         }
         catch (IllegalStateException ise)
         {
@@ -84,7 +84,7 @@ public void put(@NotNull K key, V value, long timeToLive)
                 value = _nullMarker;
 
             _cache.put(key, value, timeToLive);
-            trackPut(value);
+            trackPut(key, value);
         }
         catch (IllegalStateException ise)
         {
@@ -260,10 +260,10 @@ private V trackGet(V value)
         return value;
     }
 
-    private void trackPut(V value)
+    private void trackPut(K key, V value)
     {
         assert null != value : "Attempt to cache null into " + getDebugName() + "; must use marker for null instead.";
-        CacheManager.validate("\"" + getDebugName() + "\" cache", value);
+        CacheManager.validate("\"" + getDebugName() + "\" cache", key, value);
 
         _stats.puts.incrementAndGet();
 

api/src/org/labkey/api/cache/NightlyRecalculatingSuppliers.java

@@ -0,0 +1,132 @@
+/*
+ * Copyright (c) 2026 LabKey Corporation
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+package org.labkey.api.cache;
+
+import org.apache.logging.log4j.Logger;
+import org.jetbrains.annotations.NotNull;
+import org.labkey.api.settings.AppProps;
+import org.labkey.api.util.ExceptionUtil;
+import org.labkey.api.util.SystemMaintenance;
+import org.labkey.api.util.logging.LogHelper;
+
+import java.util.Map;
+import java.util.concurrent.ConcurrentHashMap;
+import java.util.function.Supplier;
+
+public class NightlyRecalculatingSuppliers
+{
+    private static final Logger LOG = LogHelper.getLogger(NightlyRecalculatingSuppliers.class, "Nightly recalculated values");
+    private static final Map<String, NightlyRecalculatingSupplier<?>> SUPPLIERS = new ConcurrentHashMap<>();
+    private static final BlockingCache<String, Object> CACHE =
+        CacheManager.getBlockingCache(String.class, 100, CacheManager.WEEK, "Nightly recalculated values", null);
+
+    private NightlyRecalculatingSuppliers()
+    {
+    }
+
+    /**
+     * Returns a supplier that caches the value retrieved during the first call to {@code supplier.get()} and returns
+     * that value on subsequent calls to {@code supplier.get()}. Every call to {@code NightlyRecalculatingSuppliers.get()}
+     * with the same unique name and delegate supplier class returns the same caching supplier, so the efficiency
+     * continues across multiple calls, with no need to hold the supplier. All suppliers proactively recalculate during
+     * nightly maintenance, so their values are never more than 24 hours out-of-date.
+     * @param uniqueName unique across the server; include anything the delegate captures that varies between calls
+     * @param delegate a supplier for the value that's cached. All cached values, and therefore, anything a delegate
+     *                 supplier calculates, must be unmodifiable.
+     * @return the same instance for every call with this name; the first registered delegate is kept
+     */
+    @SuppressWarnings("unchecked")
+    public static <T> Supplier<T> get(@NotNull String uniqueName, @NotNull Supplier<T> delegate)
+    {
+        NightlyRecalculatingSupplier<?> supplier = SUPPLIERS.computeIfAbsent(uniqueName, _ -> new NightlyRecalculatingSupplier<>(uniqueName, delegate));
+        Class<?> registered = supplier.delegate().getClass();
+        if (registered != delegate.getClass())
+            reportConflict("Nightly recalculating supplier \"" + uniqueName + "\" was registered by " + registered.getName() + " and again by " + delegate.getClass().getName());
+        return (Supplier<T>) supplier;
+    }
+
+    /** Computes each new value before replacing the old one, so callers rarely block on a recalculation. A failing delegate keeps its old value. */
+    private static void recalculateAll(Logger pipelineLog)
+    {
+        SUPPLIERS.values().forEach(supplier -> {
+            try
+            {
+                pipelineLog.info("Recalculating {}", supplier.name());
+                CACHE.put(supplier.name(), supplier.calculate());
+            }
+            catch (Exception e)
+            {
+                ExceptionUtil.decorateException(e, ExceptionUtil.ExceptionInfo.ExtraMessage, "Nightly recalculating supplier: " + supplier.name(), true);
+                ExceptionUtil.logExceptionToMothership(null, e);
+            }
+        });
+    }
+
+    public static class RecalculationMaintenanceTask implements SystemMaintenance.MaintenanceTask
+    {
+        @Override
+        public String getDescription()
+        {
+            return "Recalculate nightly recalculated values, such as slow usage metrics";
+        }
+
+        @Override
+        public String getName()
+        {
+            return "RecalculateNightlyValues";
+        }
+
+        @Override
+        public void run(Logger pipelineLog)
+        {
+            pipelineLog.info("Recalculating {} values", SUPPLIERS.size());
+            recalculateAll(pipelineLog);
+        }
+
+        // Disabling would leave every value frozen at its first calculation
+        @Override
+        public boolean canDisable()
+        {
+            return false;
+        }
+    }
+
+    /** Throws in dev mode; otherwise warns and keeps the first delegate */
+    private static void reportConflict(String message)
+    {
+        if (AppProps.getInstance().isDevMode())
+            throw new IllegalStateException(message);
+        LOG.warn(message);
+    }
+
+    private record NightlyRecalculatingSupplier<T>(@NotNull String name, @NotNull Supplier<T> delegate) implements Supplier<T>
+    {
+        @Override
+        @SuppressWarnings("unchecked")
+        public T get()
+        {
+            return (T) CACHE.get(name, null, (_, _) -> calculate());
+        }
+
+        private T calculate()
+        {
+            LOG.debug("Calculating {}", name);
+            T value = delegate.get();
+            LOG.debug("Calculated {}", name);
+            return value;
+        }
+    }
+}

api/src/org/labkey/api/reports/ReportService.java

@@ -71,17 +71,17 @@ static void registerProvider(ReportService provider)
      */
     void registerReport(Report report);
 
-    /** Sees every saved report during the single usage metrics pass, then adds its own metrics */
-    interface ReportMetricsVisitor
+    /** Sees every saved report during the nightly pass, then adds its own metrics */
+    interface ReportMetricsVisitor<V extends ReportMetricsVisitor<V>>
     {
         void visit(Report report);
 
-        /** Each supplier must call visitAll first; it runs the single pass on demand, so describing the metrics visits nothing */
-        void addMetrics(UsageMetrics metrics, Runnable visitAll);
+        /** Suppliers must read results from visited.get(), the cached instance that saw every report, not from this one. Calling it runs the pass on demand, so describing the metrics visits nothing. */
+        void addMetrics(UsageMetrics metrics, Supplier<V> visited);
     }
 
-    /** The factory supplies a fresh visitor for each usage metrics collection */
-    void registerReportMetricsVisitor(Supplier<ReportMetricsVisitor> factory);
+    /** The factory supplies a fresh visitor for each pass, plus one per usage metrics collection to add the metrics */
+    void registerReportMetricsVisitor(Supplier<? extends ReportMetricsVisitor<?>> factory);
 
     /**
      * A descriptor class must be registered with the service in order to be valid.

api/src/org/labkey/api/usageMetrics/UsageMetricGroup.java

@@ -19,6 +19,7 @@
 import org.jetbrains.annotations.Nullable;
 
 import java.util.Map;
+import java.util.Objects;
 import java.util.function.Supplier;
 
 /** A described nested object; its children may omit descriptions because they inherit the group's */
@@ -34,7 +35,7 @@ public UsageMetricGroup put(@NotNull String key, @Nullable Supplier<?> supplier)
     {
         Map<String, Object> values = getMutableValues();
         if (values != null)
-            values.put(key, supplier == null ? null : supplier.get());
+            values.put(key, supplier == null ? null : supply(childPath(key), supplier));
         return this;
     }
 
@@ -43,12 +44,22 @@ public UsageMetricGroup putAll(@NotNull Supplier<? extends Map<String, ?>> mapSu
     {
         Map<String, Object> mutable = getMutableValues();
         if (mutable != null)
-            mutable.putAll(mapSupplier.get());
+        {
+            Map<String, ?> map = supply(getPath(), mapSupplier);
+            if (map != null)
+                mutable.putAll(map);
+        }
         return this;
     }
 
     public UsageMetricGroup group(@NotNull String key)
     {
         return addGroup(key);
     }
+
+    @Override
+    @NotNull String getPath()
+    {
+        return Objects.requireNonNull(super.getPath());
+    }
 }

api/src/org/labkey/api/usageMetrics/UsageMetrics.java

@@ -21,12 +21,15 @@
 import org.junit.Assert;
 import org.junit.Test;
 import org.labkey.api.settings.AppProps;
+import org.labkey.api.util.ExceptionUtil;
+import org.labkey.api.util.Formats;
 import org.labkey.api.util.logging.LogHelper;
 
 import java.util.Collections;
 import java.util.LinkedHashMap;
 import java.util.List;
 import java.util.Map;
+import java.util.concurrent.TimeUnit;
 import java.util.function.BooleanSupplier;
 import java.util.function.Supplier;
 
@@ -37,7 +40,8 @@
  */
 public class UsageMetrics
 {
-    private static final Logger LOG = LogHelper.getLogger(UsageMetrics.class, "Usage metric descriptions");
+    private static final Logger LOG = LogHelper.getLogger(UsageMetrics.class, "Usage metric collection and descriptions");
+    private static final long SLOW_SUPPLIER_MS = 1000;
 
     public enum Kind
     {
@@ -83,10 +87,39 @@ public UsageMetrics put(@NotNull String key, @Nullable Supplier<?> supplier, @No
     {
         describe(key, description, kind);
         if (_values != null)
-            _values.put(key, supplier == null ? null : supplier.get());
+        {
+            Object value = supplier == null ? null : supply(childPath(key), supplier);
+            _values.put(key, value);
+        }
         return this;
     }
 
+    /** Logs slow suppliers in dev mode. A throwing supplier reports null and goes to mothership, so one broken metric doesn't drop the rest. */
+    static @Nullable <T> T supply(@NotNull String path, @NotNull Supplier<T> supplier)
+    {
+        boolean timed = AppProps.getInstance().isDevMode();
+        long start = timed ? System.nanoTime() : 0;
+        try
+        {
+            return supplier.get();
+        }
+        catch (Exception e)
+        {
+            ExceptionUtil.decorateException(e, ExceptionUtil.ExceptionInfo.ExtraMessage, "Usage metric: " + path, true);
+            ExceptionUtil.logExceptionToMothership(null, e);
+            return null;
+        }
+        finally
+        {
+            if (timed)
+            {
+                long elapsed = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start);
+                if (elapsed > SLOW_SUPPLIER_MS)
+                    LOG.warn("Usage metric {} took {} ms", path, Formats.commaf0.format(elapsed));
+            }
+        }
+    }
+
     /** @return this, or if not reported, a describe-only instance at the same path: it records descriptions of what's put into it, groups included, but drops the values */
     public UsageMetrics reportedIf(boolean reported)
     {
@@ -168,6 +201,12 @@ String childPath(String key)
         return _path == null ? key : _path + "." + key;
     }
 
+    /** @return null for the top level */
+    @Nullable String getPath()
+    {
+        return _path;
+    }
+
     /** @return null for a describe-only instance */
     @Nullable Map<String, Object> getMutableValues()
     {

core/src/org/labkey/core/CoreModule.java

@@ -48,6 +48,7 @@
 import org.labkey.api.audit.provider.GroupAuditProvider;
 import org.labkey.api.audit.provider.ModulePropertiesAuditProvider;
 import org.labkey.api.cache.CacheManager;
+import org.labkey.api.cache.NightlyRecalculatingSuppliers;
 import org.labkey.api.data.ConnectionUsage;
 import org.labkey.api.data.Container;
 import org.labkey.api.data.ContainerFilter;
@@ -1302,17 +1303,20 @@ public void moduleStartupComplete(ServletContext servletContext)
                     "Emails of active non-system users; only reported when the extended metrics feature flag is on"
                 );
 
-            metrics.put("workbookCount", () -> ContainerManager.getWorkbookCount(), "Workbooks across the server");
-            metrics.put("archivedFolderCount", () -> ContainerManager.getArchivedContainerCount(), "Archived folders across the server");
-            metrics.put("databaseSize", () -> CoreSchema.getInstance().getSchema().getScope().getDatabaseSize(), "Size of the LabKey database in bytes");
-
-            // Exclude temp schema to avoid PG exceptions when tables are appearing/disappearing during execution
-            // Note that they can be non-trivial in size.
-            SQLFragment sql = new SQLFragment("SELECT table_schema, SUM(total_size) FROM ");
-            sql.append(new PostgresTableSizesTable(new PostgresUserSchema(User.getAdminServiceUser(), ContainerManager.getRoot())), "t");
-            sql.unsafeAppend(" WHERE table_schema != 'temp' GROUP BY table_schema");
-
-            metrics.put("databaseSchemaSize", () -> new SqlSelector(CoreSchema.getInstance().getSchema(), sql).getValueMap(), "Size in bytes of each database schema, including indexes; temp excluded");
+            metrics.put("workbookCount", ContainerManager::getWorkbookCount, "Workbooks across the server");
+            metrics.put("archivedFolderCount", ContainerManager::getArchivedContainerCount, "Archived folders across the server");
+            String dbSize = "databaseSize";
+            metrics.put(dbSize, NightlyRecalculatingSuppliers.get(dbSize, () -> CoreSchema.getInstance().getSchema().getScope().getDatabaseSize()), "Size of the LabKey database in bytes");
+
+            String schemaSize = "databaseSchemaSize";
+            metrics.put(schemaSize, NightlyRecalculatingSuppliers.get(schemaSize, () -> {
+                // Exclude temp schema to avoid PG exceptions when tables are appearing/disappearing during execution
+                // Note that they can be non-trivial in size.
+                SQLFragment sql = SQLFragment.unsafe("SELECT table_schema, SUM(total_size) FROM ");
+                sql.append(new PostgresTableSizesTable(new PostgresUserSchema(User.getAdminServiceUser(), ContainerManager.getRoot())), "t");
+                sql.unsafeAppend(" WHERE table_schema != 'temp' GROUP BY table_schema");
+                return Collections.unmodifiableMap(new SqlSelector(CoreSchema.getInstance().getSchema(), sql).getValueMap());
+            }), "Size in bytes of each database schema, including indexes; temp excluded");
 
             metrics.put("scriptEngines", () -> LabKeyScriptEngineManager.get().getScriptEngineMetrics(),"Configured script engines (R, Python, etc.) keyed by name, with factory and engine class, file extensions, and whether each is external and enabled");
             metrics.put("customLabels", () -> CustomLabelService.get().getCustomLabelMetrics(), "Custom noun labels by label provider: count of relabeled nouns and of projects that override labels");