Optimize sample and list operations, including auditing and user lookups

api/src/org/labkey/api/audit/AbstractAuditHandler.java

@@ -26,14 +26,19 @@
 
 import java.util.ArrayList;
 import java.util.Collections;
+import java.util.LinkedHashMap;
 import java.util.List;
 import java.util.Map;
+import java.util.stream.Collectors;
 
 import static org.labkey.api.gwt.client.AuditBehaviorType.SUMMARY;
 
 public abstract class AbstractAuditHandler implements AuditHandler
 {
-    protected abstract AuditTypeEvent createSummaryAuditRecord(User user, Container c, AuditConfigurable tInfo, QueryService.AuditAction action, @Nullable String userComment, int rowCount, @Nullable Map<String, Object> row);
+    /** Bounds both the JDBC batch and the events held in memory while a batch accumulates. */
+    public static final int AUDIT_BATCH_SIZE = 2500;
+
+    protected abstract AuditTypeEvent createSummaryAuditRecord(User user, Container c, AuditConfigurable tInfo, QueryService.AuditAction action, @Nullable String userComment, int rowCount, @Nullable Map<String, Object> row, List<AuditTypeEvent> sideEffectEvents);
 
     @Override
     public void addSummaryAuditEvent(User user, Container c, TableInfo table, QueryService.AuditAction action, Integer dataRowCount, @Nullable AuditBehaviorType auditBehaviorType, @Nullable String userComment)
@@ -51,9 +56,11 @@ public void addSummaryAuditEvent(User user, Container c, TableInfo table, QueryS
 
             if (auditType == SUMMARY || skipAuditLevelCheck)
             {
-                AuditTypeEvent event = createSummaryAuditRecord(user, c, auditConfigurable, action, userComment, dataRowCount, null);
+                List<AuditTypeEvent> sideEffectEvents = new ArrayList<>();
+                AuditTypeEvent event = createSummaryAuditRecord(user, c, auditConfigurable, action, userComment, dataRowCount, null, sideEffectEvents);
 
                 AuditLogService.get().addEvent(user, event);
+                addSideEffectEvents(AuditLogService.get(), user, sideEffectEvents, false);
             }
         }
     }
@@ -68,9 +75,10 @@ public void addSummaryAuditEvent(User user, Container c, TableInfo table, QueryS
      * @param row            map of new data values
      * @param existingRow    map of data values
      * @param providedValues map of values provided by the user before conversion (e.g., for quantity values)
+     * @param sideEffectEvents collects audit events raised as a side effect of building this record, for the caller to flush through {@link #addSideEffectEvents}
      * @return DetailedAuditTypeEvent object describing audit record (NOTE: not committed to DB yet)
      */
-    protected abstract DetailedAuditTypeEvent createDetailedAuditRecord(User user, Container c, AuditConfigurable tInfo, QueryService.AuditAction action, @Nullable String userComment, @Nullable Map<String, Object> row, Map<String, Object> existingRow, Map<String, Object> providedValues);
+    protected abstract DetailedAuditTypeEvent createDetailedAuditRecord(User user, Container c, AuditConfigurable tInfo, QueryService.AuditAction action, @Nullable String userComment, @Nullable Map<String, Object> row, Map<String, Object> existingRow, Map<String, Object> providedValues, List<AuditTypeEvent> sideEffectEvents);
 
     /**
      * Allow for adding fields that may be present in the updated row but not represented in the original row
@@ -103,8 +111,10 @@ public void addAuditEvent(User user, Container c, TableInfo table, @Nullable Aud
 
                     case SUMMARY:
                     case DETAILED:
-                        AuditTypeEvent event = createSummaryAuditRecord(user, c, auditConfigurable, action, userComment, 0, null);
+                        List<AuditTypeEvent> truncateSideEffects = new ArrayList<>();
+                        AuditTypeEvent event = createSummaryAuditRecord(user, c, auditConfigurable, action, userComment, 0, null, truncateSideEffects);
                         AuditLogService.get().addEvent(user, event);
+                        addSideEffectEvents(AuditLogService.get(), user, truncateSideEffects, useTransactionAuditCache);
                         return;
                 }
             }
@@ -118,9 +128,11 @@ public void addAuditEvent(User user, Container c, TableInfo table, @Nullable Aud
                 {
                     assert null != rows;
 
-                    AuditTypeEvent event = createSummaryAuditRecord(user, c, auditConfigurable, action, userComment, rows.size(), rows.getFirst());
+                    List<AuditTypeEvent> sideEffectEvents = new ArrayList<>();
+                    AuditTypeEvent event = createSummaryAuditRecord(user, c, auditConfigurable, action, userComment, rows.size(), rows.getFirst(), sideEffectEvents);
 
                     AuditLogService.get().addEvent(user, event);
+                    addSideEffectEvents(AuditLogService.get(), user, sideEffectEvents, useTransactionAuditCache);
 
                     return;
                 }
@@ -130,13 +142,14 @@ public void addAuditEvent(User user, Container c, TableInfo table, @Nullable Aud
 
                     AuditLogService auditLog = AuditLogService.get();
                     List<DetailedAuditTypeEvent> batch = new ArrayList<>();
+                    List<AuditTypeEvent> sideEffectEvents = new ArrayList<>();
 
                     for (int i=0; i < rows.size(); i++)
                     {
                         Map<String, Object> row = rows.get(i);
                         Map<String, Object> existingRow = null == existingRows ? Collections.emptyMap() : existingRows.get(i);
                         Map<String, Object> providedValueRow = null == providedValues || providedValues.size() <= i  ? null : providedValues.get(i);
-                        DetailedAuditTypeEvent event = createDetailedAuditRecord(user, c, auditConfigurable, action, userComment, row, existingRow, providedValueRow);
+                        DetailedAuditTypeEvent event = createDetailedAuditRecord(user, c, auditConfigurable, action, userComment, row, existingRow, providedValueRow, sideEffectEvents);
 
                         switch (action)
                         {
@@ -175,23 +188,43 @@ public void addAuditEvent(User user, Container c, TableInfo table, @Nullable Aud
                             }
                         }
                         batch.add(event);
-                        if (batch.size() > 1000)
+                        if (batch.size() >= AUDIT_BATCH_SIZE)
                         {
                             auditLog.addEvents(user, batch, useTransactionAuditCache);
                             batch.clear();
                         }
+                        // a row can contribute more than one side effect, so bound these separately from the row batch
+                        if (sideEffectEvents.size() >= AUDIT_BATCH_SIZE)
+                        {
+                            addSideEffectEvents(auditLog, user, sideEffectEvents, useTransactionAuditCache);
+                            sideEffectEvents.clear();
+                        }
                     }
                     if (!batch.isEmpty())
                     {
                         auditLog.addEvents(user, batch, useTransactionAuditCache);
                         batch.clear();
                     }
+                    addSideEffectEvents(auditLog, user, sideEffectEvents, useTransactionAuditCache);
                     break;
                 }
             }
         }
     }
 
+    /**
+     * The one place side-effect events are written, so they can't pick up different batching or transaction-cache
+     * behavior depending on which call path produced them. insertEvents() batches only a fully homogeneous list, so
+     * group by event type and container -- each type is stored in its own provisioned table.
+     */
+    public static void addSideEffectEvents(AuditLogService auditLog, User user, List<AuditTypeEvent> events, boolean useTransactionAuditCache)
+    {
+        events.stream()
+                .collect(Collectors.groupingBy(event -> Pair.of(event.getEventType(), event.getContainer()), LinkedHashMap::new, Collectors.toList()))
+                .values()
+                .forEach(group -> auditLog.addEvents(user, group, useTransactionAuditCache));
+    }
+
     private void setOldAndNewMapsForUpdate(DetailedAuditTypeEvent event, Container c, Map<String, Object> row, Map<String, Object> existingRow, TableInfo table)
     {
         Pair<Map<String, Object>, Map<String, Object>> rowPair = AuditHandler.getOldAndNewRecordForMerge(row, existingRow, table.getExtraDetailedUpdateAuditFields(), table.getExcludedDetailedUpdateAuditFields(), table);

api/src/org/labkey/api/audit/AbstractAuditTypeProvider.java

@@ -31,6 +31,7 @@
 import org.labkey.api.data.DbScope;
 import org.labkey.api.data.MultiChoice;
 import org.labkey.api.data.MutableColumnInfo;
+import org.labkey.api.data.SchemaTableInfo;
 import org.labkey.api.data.Table;
 import org.labkey.api.data.TableInfo;
 import org.labkey.api.dataiterator.DataIterator;
@@ -85,6 +86,9 @@ public abstract class AbstractAuditTypeProvider implements AuditTypeProvider
 
     private final AbstractAuditDomainKind _domainKind;
 
+    private record CachedStorageTable(SchemaTableInfo schemaTableInfo, TableInfo storageTableInfo) {}
+    private volatile CachedStorageTable _cachedStorageTable;
+
     public AbstractAuditTypeProvider(@NotNull AbstractAuditDomainKind domainKind)
     {
         // TODO: consolidate domain kind initialization to this constructor and stop overriding getDomainKind()
@@ -266,6 +270,27 @@ public TableInfo createStorageTableInfo()
         return StorageProvisioner.createTableInfo(domain);
     }
 
+    @Override @NotNull
+    public TableInfo getStorageTableInfoForInsert()
+    {
+        Domain domain = getDomain();
+        if (null == domain)
+            throw new IllegalStateException("Could not find domain for audit event type " + getEventName());
+
+        // We want to reuse a cached provisioned TableInfo to avoid construction costs. Getting the SchemaTableInfo is
+        // cheap so use that as a guide for when the table has changed (primarily during startup as its shape may
+        // need to be updated based on current code expectations) and when it's safe to reuse the previous copy.
+        SchemaTableInfo schemaTableInfo = StorageProvisioner.get().getSchemaTableInfo(domain);
+        CachedStorageTable cached = _cachedStorageTable;
+        if (null != cached && cached.schemaTableInfo() == schemaTableInfo)
+            return cached.storageTableInfo();
+
+        TableInfo storageTableInfo = StorageProvisioner.createSharedTableInfo(domain);
+        _cachedStorageTable = new CachedStorageTable(schemaTableInfo, storageTableInfo);
+
+        return storageTableInfo;
+    }
+
     @Override
     public TableInfo createTableInfo(UserSchema userSchema, ContainerFilter cf)
     {

api/src/org/labkey/api/audit/AuditTypeProvider.java

@@ -15,6 +15,7 @@
  */
 package org.labkey.api.audit;
 
+import org.jetbrains.annotations.NotNull;
 import org.labkey.api.data.ContainerFilter;
 import org.labkey.api.data.TableInfo;
 import org.labkey.api.exp.property.Domain;
@@ -43,6 +44,14 @@ public interface AuditTypeProvider
 
     TableInfo createTableInfo(UserSchema schema, ContainerFilter cf);
 
+    /**
+     * Provisioned storage TableInfo for the insert path. Implementations should cache - creating TableInfos is expensive.
+     * Never use this to read audit rows: it has no ContainerFilter and bypasses the CanSeeAuditLog check that
+     * {@link org.labkey.api.audit.query.DefaultAuditTypeTable} applies. Go through {@link #createTableInfo} for reads.
+     */
+    @NotNull
+    TableInfo getStorageTableInfoForInsert();
+
     <K extends AuditTypeEvent> Class<K> getEventClass();
 
     ActionURL getAuditUrl();

api/src/org/labkey/api/data/MaterializedQueryHelper.java

@@ -183,15 +183,18 @@ boolean load(SQLFragment selectQuery, boolean isSelectInto)
 
                     try (var ignored = SpringActionController.ignoreSqlUpdates())
                     {
-                        for (String index : _mqh._indexes)
-                        {
-                            new SqlExecutor(_mqh._scope).execute(StringUtils.replace(index, "${NAME}", _tableName));
-                        }
+                        createIndexes(_mqh._indexes, false);
                         analyze();
                     }
                 });
 
+                // Published here, not after the deferred indexes: those only make the table faster, and building them
+                // first keeps every reader on the unmaterialized query for the length of the slowest index.
                 _loadingState.set(LoadingState.LOADED);
+
+                if (!_mqh._deferredIndexes.isEmpty())
+                    traced("full.deferredIndexes", _mqh.getMaterializationName(), () -> createIndexes(_mqh._deferredIndexes, true));
+
                 return true;
             }
             catch (RuntimeException rex)
@@ -206,6 +209,28 @@ boolean load(SQLFragment selectQuery, boolean isSelectInto)
             }
         }
 
+        /**
+         * @param tolerateFailure true once the table is serving reads, where a missing index costs speed but nothing else,
+         *                        so the failure is logged and the remaining indexes are still attempted
+         */
+        private void createIndexes(List<String> indexes, boolean tolerateFailure)
+        {
+            for (String index : indexes)
+            {
+                String sql = StringUtils.replace(index, "${NAME}", _tableName);
+                try
+                {
+                    new SqlExecutor(_mqh._scope).execute(sql);
+                }
+                catch (RuntimeException x)
+                {
+                    if (!tolerateFailure)
+                        throw x;
+                    LOG.error("Failed to create index on materialized table {}. The table is serving queries without it. DDL: {}", _tableName, sql, x);
+                }
+            }
+        }
+
         /** SELECT INTO leaves the table with no statistics, so the planner guesses until autovacuum eventually analyzes it. */
         private void analyze()
         {
@@ -389,6 +414,7 @@ private String makeKey(DbScope.Transaction t)
     protected final SQLFragment _uptodateQuery;
     protected final Supplier<String> _supplier;
     private final List<String> _indexes = new ArrayList<>();
+    private final List<String> _deferredIndexes = new ArrayList<>();
     protected final long _maxTimeToCache;
     private final Map<String, Materialized> _map = Collections.synchronizedMap(new LinkedHashMap<>()
     {
@@ -410,7 +436,7 @@ protected boolean removeEldestEntry(Map.Entry<String, Materialized> eldest)
 
     private boolean _closed = false;
 
-    protected MaterializedQueryHelper(String prefix, DbScope scope, SQLFragment select, @Nullable SQLFragment uptodate, Supplier<String> supplier, @Nullable Collection<String> indexes, long maxTimeToCache,
+    protected MaterializedQueryHelper(String prefix, DbScope scope, SQLFragment select, @Nullable SQLFragment uptodate, Supplier<String> supplier, @Nullable Collection<String> indexes, @Nullable Collection<String> deferredIndexes, long maxTimeToCache,
                                     boolean isSelectIntoSql, boolean unlogged)
     {
         _prefix = Objects.toString(prefix,"mat");
@@ -421,6 +447,8 @@ protected MaterializedQueryHelper(String prefix, DbScope scope, SQLFragment sele
         _maxTimeToCache = maxTimeToCache;
         if (null != indexes)
             _indexes.addAll(indexes);
+        if (null != deferredIndexes)
+            _deferredIndexes.addAll(deferredIndexes);
         _isSelectIntoSql = isSelectIntoSql;
         _unlogged = unlogged;
         assert MemTracker.get().put(this);
@@ -769,14 +797,14 @@ protected void initMaterialized(Materialized materialized)
     @Deprecated // use Builder
     public static MaterializedQueryHelper create(String prefix, DbScope scope, SQLFragment select, @Nullable SQLFragment uptodate, Collection<String> indexes, long maxTimeToCache)
     {
-        return new MaterializedQueryHelper(prefix, scope, select, uptodate, null, indexes, maxTimeToCache, false, false);
+        return new MaterializedQueryHelper(prefix, scope, select, uptodate, null, indexes, null, maxTimeToCache, false, false);
     }
 
 
     @Deprecated // use Builder
     public static MaterializedQueryHelper create(String prefix, DbScope scope, SQLFragment select, Supplier<String> uptodate, Collection<String> indexes, long maxTimeToCache)
     {
-        return new MaterializedQueryHelper(prefix, scope, select, null, uptodate, indexes, maxTimeToCache, false, false);
+        return new MaterializedQueryHelper(prefix, scope, select, null, uptodate, indexes, null, maxTimeToCache, false, false);
     }
 
     public static class Builder implements org.labkey.api.data.Builder<MaterializedQueryHelper>
@@ -791,6 +819,7 @@ public static class Builder implements org.labkey.api.data.Builder<MaterializedQ
         protected SQLFragment _uptodate = null;
         protected Supplier<String> _supplier = null;
         protected Collection<String> _indexes = new ArrayList<>();
+        protected Collection<String> _deferredIndexes = new ArrayList<>();
 
         public Builder(String prefix, DbScope scope, SQLFragment select)
         {
@@ -834,16 +863,24 @@ public Builder addInvalidCheck(Supplier<String> supplier)
             return this;
         }
 
+        /** Index built before the table is published, for anything a reader or the incremental maintenance SQL cannot go without. */
         public Builder addIndex(String index)
         {
             _indexes.add(index);
             return this;
         }
 
+        /** Index built after the table is published to readers; a failure is logged and the table serves without it. */
+        public Builder addDeferredIndex(String index)
+        {
+            _deferredIndexes.add(index);
+            return this;
+        }
+
         @Override
         public MaterializedQueryHelper build()
         {
-            return new MaterializedQueryHelper(_prefix, _scope, _select, _uptodate, _supplier, _indexes, _max, _isSelectInto, _unlogged);
+            return new MaterializedQueryHelper(_prefix, _scope, _select, _uptodate, _supplier, _indexes, _deferredIndexes, _max, _isSelectInto, _unlogged);
         }
     }