From b882e3d0f0627062729aab786b5a5cf618c11c25 Mon Sep 17 00:00:00 2001 From: James Maes Date: Thu, 15 Oct 2026 17:40:01 -0500 Subject: [PATCH] fix(collect): no stack overflow on huge statements; every failure closes the run The normalizer folded IN and VALUES lists with nested-repetition regular expressions, which threw StackOverflowError on kof22's 60 KB statements. That Error escaped catch(Exception), so runs stayed RUNNING, nothing was logged and no alert fired. List folding is now a linear token scan, the collector catches Throwable (rethrowing OutOfMemoryError), logs class and frame at ERROR, marks FAILED and alerts, and stale RUNNING runs are closed. Verified against kof22's 4,462 real statement texts (under 1 s). Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 1 + .../collect/SnapshotCollector.java | 46 +++++++++- .../normalize/SqlNormalizer.java | 83 ++++++++++++++++++- .../dbperformance/DbPerfFixtureProvider.java | 5 ++ .../dbperformance/SnapshotCollectorTest.java | 31 +++++++ .../dbperformance/SqlNormalizerTest.java | 8 ++ 6 files changed, 169 insertions(+), 5 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 7d4dd71..e53fd1a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,7 @@ All notable changes are documented here. This project follows Keep a Changelog a ## [Unreleased] ### Fixed +- Collection no longer stops at RUNNING on large production statement sets: list folding in the SQL normalizer is a linear token scan (the nested-repetition regular expressions overflowed the stack on 60 KB statements with long IN/VALUES lists). Any failure, including an `Error`, now closes the run as FAILED with the exception class, logs it at ERROR (class and frame only, never SQL text) and raises the collection alert; runs left RUNNING by a crash are closed as FAILED after three intervals. - Only one runtime attributes per JVM: starting attribution on a newer instance (a hot swap, or repeated server starts in tests) stops the previous one, so old instances are never pinned by a forgotten listener and flusher. - Each table has its own icon (the app icon is now `storage`), so nav entries are distinguishable and do not repeat icons used elsewhere. - Home tables keep at most four columns with plain headers (readable at every width): secondary facts such as calls and mean time, the session's query text, and a unit's kind and top table move into a second line of the first cell. diff --git a/src/main/java/com/kingsrook/qbits/dbperformance/collect/SnapshotCollector.java b/src/main/java/com/kingsrook/qbits/dbperformance/collect/SnapshotCollector.java index af1a57e..ef6b5a4 100644 --- a/src/main/java/com/kingsrook/qbits/dbperformance/collect/SnapshotCollector.java +++ b/src/main/java/com/kingsrook/qbits/dbperformance/collect/SnapshotCollector.java @@ -48,6 +48,7 @@ import com.kingsrook.qbits.dbperformance.provider.ProviderCapabilities; import com.kingsrook.qbits.dbperformance.provider.SessionInfo; import com.kingsrook.qbits.dbperformance.provider.StatementStats; import com.kingsrook.qbits.dbperformance.provider.TableStats; +import com.kingsrook.qqq.backend.core.logging.QLogger; import com.kingsrook.qqq.backend.core.model.actions.tables.query.QCriteriaOperator; import com.kingsrook.qqq.backend.core.model.actions.tables.query.QFilterCriteria; import com.kingsrook.qqq.backend.core.model.actions.tables.query.QFilterOrderBy; @@ -55,6 +56,7 @@ import com.kingsrook.qqq.backend.core.model.actions.tables.query.QQueryFilter; import com.kingsrook.qqq.backend.core.model.data.QRecord; import com.kingsrook.qqq.backend.module.rdbms.jdbc.ConnectionManager; import com.kingsrook.qqq.backend.module.rdbms.model.metadata.RDBMSBackendMetaData; +import static com.kingsrook.qqq.backend.core.logging.LogUtils.logPair; /******************************************************************************* @@ -62,6 +64,8 @@ import com.kingsrook.qqq.backend.module.rdbms.model.metadata.RDBMSBackendMetaDat *******************************************************************************/ public class SnapshotCollector { + private static final QLogger LOG = QLogger.getLogger(SnapshotCollector.class); + private final DbPerfRuntime runtime; private final Clock clock; private final DbStatsProvider providerOverride; @@ -104,6 +108,7 @@ public class SnapshotCollector throw (new IllegalArgumentException("Backend is not configured for this runtime")); } QRecord settings = new DbPerfSettingsService(runtime).ensure(backendName); + failAbandonedRuns(backendName, settings); QRecord inserted = runtime.asSystem(() -> DbPerfStore.insert("db_perf_snapshot", List.of(snapshot)).getFirst()); snapshot.setValue("id", inserted.getValueInteger("id")); runtime.transaction(() -> @@ -121,9 +126,19 @@ public class SnapshotCollector return (null); }); } - catch(Exception e) + catch(Throwable e) { - // Never persist a JDBC exception message: it may contain SQL literals. + ////////////////////////////////////////////////////////////////////////// + // Errors too (a StackOverflowError once left runs RUNNING with no log). // + // Never persist or log a JDBC exception message: it may contain SQL // + // literals. The class and the throwing frame identify the cause. // + ////////////////////////////////////////////////////////////////////////// + if(e instanceof OutOfMemoryError outOfMemory) + { + throw (outOfMemory); + } + LOG.error("Database performance snapshot failed", logPair("backend", backendName), logPair("snapshotId", snapshot.getValueInteger("id")), + logPair("exception", e.getClass().getName()), logPair("at", e.getStackTrace().length == 0 ? null : e.getStackTrace()[0].toString())); snapshot.withValue("status", "FAILED").withValue("errorMessage", "Collection failed (" + e.getClass().getSimpleName() + "). Check database connectivity, schema and statistics access.") .withValue("durationMs", (int) Math.min(Integer.MAX_VALUE, (System.nanoTime() - started) / 1000000)); if(snapshot.getValueInteger("id") != null) @@ -149,6 +164,33 @@ public class SnapshotCollector } + /******************************************************************************* + ** Runs left RUNNING by a crashed pod or an earlier failure are closed as + ** FAILED once they are older than three collection intervals. + *******************************************************************************/ + private void failAbandonedRuns(String backendName, QRecord settings) throws Exception + { + int interval = positive(settings, "snapshotIntervalMinutes", 5); + Instant cutoff = clock.instant().minus(Duration.ofMinutes(3L * interval)); + List abandoned = runtime.asSystem(() -> DbPerfStore.query("db_perf_snapshot", DbPerfStore.eq("backendName", backendName) + .withCriteria(new QFilterCriteria("status", QCriteriaOperator.EQUALS, "RUNNING")) + .withCriteria(new QFilterCriteria("capturedAt", QCriteriaOperator.LESS_THAN, cutoff)))); + if(abandoned.isEmpty()) + { + return; + } + List updates = abandoned.stream().map(row -> new QRecord().withValue("id", row.getValueInteger("id")).withValue("status", "FAILED") + .withValue("errorMessage", "Collection did not finish (the run was interrupted or its pod stopped).")).toList(); + runtime.asSystem(() -> + { + DbPerfStore.update("db_perf_snapshot", updates); + return (null); + }); + LOG.warn("Closed abandoned database performance snapshots", logPair("backend", backendName), logPair("count", updates.size())); + } + + + /******************************************************************************* ** Statistics read and writes under the ambient system transaction. *******************************************************************************/ diff --git a/src/main/java/com/kingsrook/qbits/dbperformance/normalize/SqlNormalizer.java b/src/main/java/com/kingsrook/qbits/dbperformance/normalize/SqlNormalizer.java index 4b380fc..704bd78 100644 --- a/src/main/java/com/kingsrook/qbits/dbperformance/normalize/SqlNormalizer.java +++ b/src/main/java/com/kingsrook/qbits/dbperformance/normalize/SqlNormalizer.java @@ -24,7 +24,10 @@ package com.kingsrook.qbits.dbperformance.normalize; import java.nio.charset.StandardCharsets; import java.security.MessageDigest; import java.security.NoSuchAlgorithmException; +import java.util.ArrayList; +import java.util.Arrays; import java.util.HexFormat; +import java.util.List; import java.util.Locale; import java.util.regex.Matcher; import java.util.regex.Pattern; @@ -200,12 +203,86 @@ public final class SqlNormalizer *******************************************************************************/ private static String collapseLists(String normalized) { - normalized = normalized.replaceAll("\\bin \\( \\?(?: , \\?)* \\)", "in ( ? )"); - normalized = normalized.replaceAll("\\bvalues (\\( \\?(?: , \\?)* \\))(?: , \\( \\?(?: , \\?)* \\))+", "values $1"); - return (normalized); + /////////////////////////////////////////////////////////////////////////// + // a linear scan over the space-separated tokens: regular expressions // + // with nested repetition overflow the stack on very long IN and VALUES // + // lists (seen with 60 KB statements in production) // + /////////////////////////////////////////////////////////////////////////// + //////////////////////////////////////////////////////////////////////// + // segments between quoted identifiers keep their edge spaces // + //////////////////////////////////////////////////////////////////////// + String trimmed = normalized.strip(); + if(trimmed.isEmpty()) + { + return (normalized); + } + String leading = normalized.substring(0, normalized.indexOf(trimmed.charAt(0))); + String trailing = normalized.substring(leading.length() + trimmed.length()); + String[] tokens = trimmed.split(" "); + List out = new ArrayList<>(tokens.length); + int i = 0; + while(i < tokens.length) + { + String token = tokens[i]; + if("in".equals(token)) + { + int end = placeholderGroupEnd(tokens, i + 1); + if(end > 0) + { + out.addAll(List.of("in", "(", "?", ")")); + i = end; + continue; + } + } + if("values".equals(token)) + { + int first = placeholderGroupEnd(tokens, i + 1); + if(first > 0) + { + int end = first; + while(end + 1 < tokens.length && ",".equals(tokens[end])) + { + int next = placeholderGroupEnd(tokens, end + 1); + if(next < 0) + { + break; + } + end = next; + } + out.add("values"); + out.addAll(Arrays.asList(tokens).subList(i + 1, first)); + i = end; + continue; + } + } + out.add(token); + i++; + } + return (leading + String.join(" ", out) + trailing); } + + /******************************************************************************* + ** If tokens[start] opens "( ? , ? ... )" made only of placeholders, the index + ** just after its ")"; otherwise -1. + *******************************************************************************/ + private static int placeholderGroupEnd(String[] tokens, int start) + { + if(start + 2 >= tokens.length || !"(".equals(tokens[start]) || !"?".equals(tokens[start + 1])) + { + return (-1); + } + int i = start + 2; + while(i + 1 < tokens.length && ",".equals(tokens[i]) && "?".equals(tokens[i + 1])) + { + i += 2; + } + return (i < tokens.length && ")".equals(tokens[i]) ? i + 1 : -1); + } + + + /******************************************************************************* ** Consume a quote with SQL doubled-quote and optional escape handling. *******************************************************************************/ diff --git a/src/test/java/com/kingsrook/qbits/dbperformance/DbPerfFixtureProvider.java b/src/test/java/com/kingsrook/qbits/dbperformance/DbPerfFixtureProvider.java index 3d38706..da5c6f9 100644 --- a/src/test/java/com/kingsrook/qbits/dbperformance/DbPerfFixtureProvider.java +++ b/src/test/java/com/kingsrook/qbits/dbperformance/DbPerfFixtureProvider.java @@ -47,6 +47,7 @@ public class DbPerfFixtureProvider extends UnsupportedStatsProvider public Instant reset = START.minusSeconds(3600); public boolean limited; public boolean fail; + public Error error; /******************************************************************************* @@ -85,6 +86,10 @@ public class DbPerfFixtureProvider extends UnsupportedStatsProvider @Override public List readStatements(Connection connection) { + if(error != null) + { + throw (error); + } return (List.of(new StatementStats(1, "app", true, "select * from public.accounts where id=$1", calls, BigDecimal.valueOf(calls * 10), BigDecimal.TEN, BigDecimal.valueOf(15), calls, calls * 9, calls, 0, reset, reset), new StatementStats(2, "app", true, "select * from public.accounts where name='private'", calls, BigDecimal.valueOf(calls * 5), BigDecimal.valueOf(5), BigDecimal.TEN, calls, calls, calls, 2, reset, reset))); } diff --git a/src/test/java/com/kingsrook/qbits/dbperformance/SnapshotCollectorTest.java b/src/test/java/com/kingsrook/qbits/dbperformance/SnapshotCollectorTest.java index a46c6bd..3aa247d 100644 --- a/src/test/java/com/kingsrook/qbits/dbperformance/SnapshotCollectorTest.java +++ b/src/test/java/com/kingsrook/qbits/dbperformance/SnapshotCollectorTest.java @@ -123,6 +123,37 @@ class SnapshotCollectorTest } + /******************************************************************************* + ** An Error (not just an Exception) still closes the run as FAILED, and runs + ** left RUNNING by an earlier crash are closed once they are stale. + *******************************************************************************/ + @Test + void errorsAndAbandonedRuns() throws Exception + { + QInstance instance = DbPerfTestSupport.instance(); + DbPerfRuntime runtime = DbPerfRuntime.of(instance); + DbPerfFixtureProvider provider = new DbPerfFixtureProvider(); + runtime.asSystem(() -> DbPerfStore.insert("db_perf_snapshot", List.of(new QRecord().withValue("backendName", runtime.getConfig().getBackendName()) + .withValue("capturedAt", DbPerfFixtureProvider.START.minusSeconds(3600)).withValue("status", "RUNNING")))); + + provider.error = new StackOverflowError(); + QRecord failed = collect(runtime, provider, 0, true); + assertThat(failed.getValueString("status")).isEqualTo("FAILED"); + assertThat(failed.getValueString("errorMessage")).contains("StackOverflowError"); + runtime.asSystem(() -> + { + List rows = DbPerfStore.query("db_perf_snapshot", new QQueryFilter()); + assertThat(rows).hasSize(2).allSatisfy(row -> assertThat(row.getValueString("status")).isEqualTo("FAILED")); + assertThat(rows).anySatisfy(row -> assertThat(row.getValueString("errorMessage")).contains("did not finish")); + return (null); + }); + + provider.error = null; + assertThat(collect(runtime, provider, 300, true).getValueString("status")).isEqualTo("OK"); + } + + + /******************************************************************************* ** H2 remains usable and explicitly unsupported by the production selector. *******************************************************************************/ diff --git a/src/test/java/com/kingsrook/qbits/dbperformance/SqlNormalizerTest.java b/src/test/java/com/kingsrook/qbits/dbperformance/SqlNormalizerTest.java index 8439602..5e53c5d 100644 --- a/src/test/java/com/kingsrook/qbits/dbperformance/SqlNormalizerTest.java +++ b/src/test/java/com/kingsrook/qbits/dbperformance/SqlNormalizerTest.java @@ -86,6 +86,14 @@ class SqlNormalizerTest assertThat(SqlNormalizer.mainTable("select 1")).isNull(); assertThat(SqlNormalizer.normalize("select \"in ( ? , ? )\" from t")).isEqualTo("select \"in ( ? , ? )\" from t"); assertThat(SqlNormalizer.normalize(null)).isEmpty(); + /////////////////////////////////////////////////////////////////////// + // huge lists (production had 60 KB statements) must not overflow // + /////////////////////////////////////////////////////////////////////// + String hugeIn = "select * from t where id in (" + "$1, ".repeat(20000) + "$1)"; + assertThat(SqlNormalizer.normalize(hugeIn)).isEqualTo("select * from t where id in ( ? )"); + String hugeValues = "insert into t (a, b) values " + "($1, $2), ".repeat(20000) + "($1, $2)"; + assertThat(SqlNormalizer.normalize(hugeValues)).isEqualTo("insert into t ( a , b ) values ( ? , ? )"); + assertThat(SqlNormalizer.normalize("select * from t where id in (1, x)")).isEqualTo("select * from t where id in ( ? , x )"); assertThat(SqlNormalizer.normalize(" ")).isEmpty(); assertThat(SqlNormalizer.normalize("select " + "field, ".repeat(5000))).hasSize(10000); } -- 2.54.0