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); }