diff --git a/ModuleConfig.bx b/ModuleConfig.bx index cbeb98c..db8950d 100644 --- a/ModuleConfig.bx +++ b/ModuleConfig.bx @@ -42,7 +42,15 @@ class { // Datasource name SQLiteMetricsStore reads/writes, if you opt into it above. datasourceName = "rulebox_visualizer", // Max live-tracker (SSE) connections open at once; each pins two server threads. Over the cap, stream() answers 503. - maxStreams = 25 + maxStreams = 25, + // SQLiteMetricsStore retention (0 disables either): prune events older than this many days... + retentionDays = 30, + // ...and keep at most this many rows. Checked every ~500 inserts, not on every insert. + maxStoredEvents = 100000, + // SQLiteMetricsStore circuit breaker: after this many consecutive failures stop + // writing for the cool-down (seconds), logging one error on open and one info on recovery. + circuitBreakerThreshold = 5, + circuitBreakerCooldownSeconds = 60 } } @@ -101,7 +109,11 @@ class { } // Whole-number settings and the smallest value each accepts var minimums = { - maxStreams : 1 + retentionDays : 0, + maxStoredEvents : 0, + circuitBreakerThreshold : 1, + circuitBreakerCooldownSeconds : 0, + maxStreams : 1 } for( var key, minimum in minimums ){ var value = arguments.visualizer[ key ] ?: "" diff --git a/docs/guides/visualizer.md b/docs/guides/visualizer.md index 061f597..84a1d4f 100644 --- a/docs/guides/visualizer.md +++ b/docs/guides/visualizer.md @@ -225,6 +225,33 @@ you opt into this store, you set these up yourself. If `bx-sqlite` or the datasource isn't available, RuleBox logs it and keeps going: live broadcast still works, nothing gets persisted. +#### Retention, indexing and the circuit breaker + +The SQLite store is hardened for long-running apps. All of these settings live +under `visualizer` and are optional: + +| Setting | Default | Meaning | +| --- | --- | --- | +| `retentionDays` | `30` | Delete events older than this many days. `0` disables. | +| `maxStoredEvents` | `100000` | Keep at most this many rows (the newest). `0` disables. | +| `circuitBreakerThreshold` | `5` | Consecutive failed writes before the store stops trying. | +| `circuitBreakerCooldownSeconds` | `60` | How long it stays idle before a single trial write. | + +- Retention is enforced by a cheap `DELETE` once every 500 inserts, never on + every insert, so the table can briefly exceed the limits between prunes. +- The `rulebox_events` table has an index on `(rulebookName, ruleName, id)` for + the per-rule metrics queries (created automatically; existing tables get it + on the next startup). +- If writes keep failing (a missing datasource, a locked or full database), the + store logs **one** error when the breaker opens, skips persistence for the + cool-down (live broadcast keeps working), then retries once and logs **one** + info line when it recovers. A failed schema create is retried on the next + event rather than being swallowed for good. +- Each recorded event is still a synchronous `INSERT` on the thread that + evaluated the rule. That is a deliberate trade-off for simplicity; if it is + too slow for your traffic, use the in-memory store or implement + `IMetricsStore@rulebox` with a queue. + ### Swapping it out Implement `IMetricsStore@rulebox` (`recordEvent`, `queryEvents`, diff --git a/models/metrics/IMetricsStore.bx b/models/metrics/IMetricsStore.bx index 204b1d0..78b6a0a 100644 --- a/models/metrics/IMetricsStore.bx +++ b/models/metrics/IMetricsStore.bx @@ -1,7 +1,7 @@ /** * Contract for a Rule Visualizer metrics persistence store. Implement this and point * moduleSettings.rulebox.visualizer.metricsStore at your WireBox mapping to swap out the - * default SQLiteMetricsStore@rulebox. + * default InMemoryMetricsStore@rulebox (or the opt-in SQLiteMetricsStore@rulebox). */ interface { diff --git a/models/metrics/SQLiteMetricsStore.bx b/models/metrics/SQLiteMetricsStore.bx index 11df895..565cbae 100644 --- a/models/metrics/SQLiteMetricsStore.bx +++ b/models/metrics/SQLiteMetricsStore.bx @@ -1,14 +1,26 @@ /** - * Default IMetricsStore for the Rule Visualizer: persists rule-evaluation events to a SQLite - * table via the bx-sqlite module, so metrics/stats survive a restart. + * Opt-in persistent IMetricsStore for the Rule Visualizer: persists rule-evaluation events to a + * SQLite table via the bx-sqlite module, so metrics/stats survive a restart. (The default store is + * InMemoryMetricsStore@rulebox; point visualizer.metricsStore at "SQLiteMetricsStore@rulebox" to opt in.) * * Requires the bx-sqlite BoxLang module and a datasource registered under * moduleSettings.rulebox.visualizer.datasourceName (default "rulebox_visualizer"). Neither is * installed/declared by RuleBox itself - see the "Rule Visualizer" guide for setup. * + * Hardening: + * - Circuit breaker: after visualizer.circuitBreakerThreshold (5) consecutive failures the store + * stops touching the database for visualizer.circuitBreakerCooldownSeconds (60), logging ONE error + * when it opens and one info line when it recovers. While open, recordEvent() is a cheap no-op. + * - Schema: a failed schema create is remembered and re-attempted by the next recordEvent(). + * An index on (rulebookName, ruleName, id) backs the per-rule metrics queries. + * - Retention: visualizer.retentionDays (30) and visualizer.maxStoredEvents (100000) are enforced + * by a cheap DELETE every pruneEvery (500) inserts - never on every insert. 0 disables either. + * - recordEvent() still performs a synchronous INSERT on the calling thread (a documented trade-off). + * * Swap this out entirely via moduleSettings.rulebox.visualizer.metricsStore. */ @singleton +@threadsafe class implements="IMetricsStore"{ @inject( "coldbox:moduleSettings:rulebox" ) @@ -17,51 +29,327 @@ class implements="IMetricsStore"{ @inject( "logbox:logger:{this}" ) property name="logger"; + /** + * The datasource events are written to, read from visualizer.datasourceName in onDIComplete() + */ property name="datasourceName" type="string"; + /** + * Consecutive failures that open the circuit, from visualizer.circuitBreakerThreshold + */ + property name="breakerThreshold" type="numeric" default="5"; + + /** + * How long the circuit stays open before a trial insert, in milliseconds, from + * visualizer.circuitBreakerCooldownSeconds + */ + property name="breakerCooldownMs" type="numeric" default="60000"; + + /** + * Prune events older than this many days, from visualizer.retentionDays. 0 disables it. + */ + property name="retentionDays" type="numeric" default="30"; + + /** + * Keep at most this many rows, from visualizer.maxStoredEvents. 0 disables it. + */ + property name="maxStoredEvents" type="numeric" default="100000"; + + /** + * Run the retention DELETE once per this many successful inserts + */ + property name="pruneEvery" type="numeric" default="500"; + + /** + * Has the events table and its index been created? A failed create is retried by the next recordEvent(). + */ + property name="schemaReady" type="boolean" default="false"; + + /** + * Failures in a row since the last successful database call + */ + property name="consecutiveFailures" type="numeric" default="0"; + + /** + * Is the circuit open (tripped and not yet recovered)? + */ + property name="circuitOpen" type="boolean" default="false"; + + /** + * When the circuit opened, or when the last trial was claimed, in milliseconds + */ + property name="circuitOpenedAt" type="numeric" default="0"; + + /** + * Successful inserts since the last retention prune + */ + property name="insertsSincePrune" type="numeric" default="0"; + + /** + * The message of the most recent database failure + */ + property name="lastError" type="string" default=""; + + /** + * Executes SQL: ( sql, params, options ) => result. Null means queryExecute() against the configured + * datasource. Set it with setSqlRunner() to unit-test the breaker and retention logic. + */ + property name="sqlRunner" type="function"; + + /** + * The circuit breaker's clock: () => epoch milliseconds. Null means getTickCount(). Set it with + * setClock() to unit-test the cool-down. + */ + property name="clock" type="function"; + + /** + * Read the visualizer settings (already filled and validated by ModuleConfig) and create the schema + * + * @return This store + */ function onDIComplete(){ - variables.datasourceName = variables.settings.visualizer.datasourceName - ensureSchema() + var viz = variables.settings.visualizer + variables.datasourceName = viz.datasourceName + variables.breakerThreshold = viz.circuitBreakerThreshold + variables.breakerCooldownMs = viz.circuitBreakerCooldownSeconds * 1000 + variables.retentionDays = viz.retentionDays + variables.maxStoredEvents = viz.maxStoredEvents + ensureSchema( true ) return this } - private void function ensureSchema(){ - try{ - queryExecute( - " - CREATE TABLE IF NOT EXISTS rulebox_events ( - id INTEGER PRIMARY KEY AUTOINCREMENT, - rulebookName TEXT NOT NULL, - ruleName TEXT NOT NULL, - state TEXT NOT NULL, - durationMs REAL NOT NULL, - timestamp TEXT NOT NULL + /** + * May we touch the database right now? Always true while closed. While open it is false until the + * cool-down elapses, then true for exactly one caller (which becomes the trial) per cool-down. + */ + boolean function canAttempt(){ + if( !variables.circuitOpen ){ + return true + } + var allowed = false + lock name="rulebox_sqlite_store_state" type="exclusive" timeout="5"{ + var now = nowMillis() + if( variables.circuitOpen && ( now - variables.circuitOpenedAt ) >= variables.breakerCooldownMs ){ + // Claim the trial; others stay shut out until the next cool-down or until we close it + variables.circuitOpenedAt = now + allowed = true + } else { + allowed = !variables.circuitOpen + } + } + return allowed + } + + /** + * Count one failure; opens the circuit (logging ONE error) at the threshold. + */ + void function recordFailure( required string message ){ + lock name="rulebox_sqlite_store_state" type="exclusive" timeout="5"{ + variables.consecutiveFailures++ + variables.lastError = arguments.message + if( variables.circuitOpen ){ + // A failed trial: stay open for another cool-down, quietly + variables.circuitOpenedAt = nowMillis() + } else if( variables.consecutiveFailures >= variables.breakerThreshold ){ + variables.circuitOpen = true + variables.circuitOpenedAt = nowMillis() + logger.error( + "RuleBox SQLiteMetricsStore: #variables.consecutiveFailures# consecutive failures on datasource '#variables.datasourceName#'; pausing metric persistence for #variables.breakerCooldownMs / 1000# seconds (live broadcast is unaffected). Last error: #arguments.message#" ) - ", - {}, - { datasource: variables.datasourceName } + } else { + logger.debug( "RuleBox SQLiteMetricsStore failure #variables.consecutiveFailures#/#variables.breakerThreshold#: #arguments.message#" ) + } + } + } + + /** + * Reset the failure count; closes the circuit (logging one info line) if it was open. + */ + void function recordSuccess(){ + if( variables.consecutiveFailures == 0 && !variables.circuitOpen ){ + return + } + lock name="rulebox_sqlite_store_state" type="exclusive" timeout="5"{ + var wasOpen = variables.circuitOpen + variables.consecutiveFailures = 0 + variables.circuitOpen = false + variables.lastError = "" + if( wasOpen ){ + logger.info( "RuleBox SQLiteMetricsStore recovered on datasource '#variables.datasourceName#'; resuming metric persistence." ) + } + } + } + + /** + * Count one successful insert and report whether the retention prune is due (every pruneEvery + * inserts). Always false when both retention limits are disabled. + */ + boolean function shouldPrune(){ + if( variables.retentionDays <= 0 && variables.maxStoredEvents <= 0 ){ + return false + } + var due = false + lock name="rulebox_sqlite_store_state" type="exclusive" timeout="5"{ + variables.insertsSincePrune++ + if( variables.insertsSincePrune >= variables.pruneEvery ){ + variables.insertsSincePrune = 0 + due = true + } + } + return due + } + + /** + * The DDL ensureSchema() runs: the table, then the index backing queryRuleMetrics(). + */ + array function getSchemaStatements(){ + return [ + " + CREATE TABLE IF NOT EXISTS rulebox_events ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + rulebookName TEXT NOT NULL, + ruleName TEXT NOT NULL, + state TEXT NOT NULL, + durationMs REAL NOT NULL, + timestamp TEXT NOT NULL ) + ", + "CREATE INDEX IF NOT EXISTS idx_rulebox_events_rule ON rulebox_events ( rulebookName, ruleName, id )" + ] + } + + /** + * The retention DELETEs for the configured limits, as [ { sql, params } ]. + * + * @asOf The reference "now" for retentionDays (injectable for tests) + */ + array function buildPruneStatements( date asOf=now() ){ + var statements = [] + if( variables.maxStoredEvents > 0 ){ + // ids only grow, so "everything older than the newest N ids" is a cheap primary-key range delete + statements.append( { + sql : "DELETE FROM rulebox_events WHERE id <= ( SELECT MAX( id ) FROM rulebox_events ) - :maxEvents", + params : { maxEvents: { value: variables.maxStoredEvents, cfsqltype: "integer" } } + } ) + } + if( variables.retentionDays > 0 ){ + var cutoff = dateTimeFormat( dateAdd( "d", -variables.retentionDays, arguments.asOf ), "yyyy-MM-dd'T'HH:mm:ss" ) + statements.append( { + sql : "DELETE FROM rulebox_events WHERE timestamp < :cutoff", + params : { cutoff: { value: cutoff, cfsqltype: "varchar" } } + } ) + } + return statements + } + + /** + * Run the retention DELETEs. A prune failure is logged but never trips the breaker. + */ + void function prune(){ + try{ + var statements = buildPruneStatements() + for( var stmt in statements ){ + runSql( stmt.sql, stmt.params ) + } } catch( any e ){ - logger.error( - "RuleBox visualizer could not create/verify its SQLite schema on datasource '#variables.datasourceName#'. Is the bx-sqlite module installed and is that datasource registered? #e.message# #e.detail#" - ) + logger.warn( "RuleBox SQLiteMetricsStore could not prune old events: #e.message# #e.detail#" ) + } + } + + /** + * Create the table/index if needed. A failure is remembered (schemaReady=false) and counts toward + * the breaker; recordEvent() re-attempts it before inserting. + * + * @initial True from onDIComplete(): log a warning (later retries stay quiet until the breaker opens) + */ + private boolean function ensureSchema( boolean initial=false ){ + try{ + var statements = getSchemaStatements() + for( var sql in statements ){ + runSql( sql ) + } + variables.schemaReady = true + return true + } catch( any e ){ + variables.schemaReady = false + var msg = "#e.message# #e.detail#" + if( arguments.initial ){ + logger.warn( + "RuleBox visualizer could not create/verify its SQLite schema on datasource '#variables.datasourceName#'; will retry when the next event is recorded. Is the bx-sqlite module installed and is that datasource registered? #msg#" + ) + } + recordFailure( msg ) + return false } } + /** + * Persist one rule-evaluation event. A no-op while the circuit is open. + * + * @event { rulebookName, ruleName, state, durationMs, timestamp } + */ void function recordEvent( required struct event ){ - queryExecute( - "INSERT INTO rulebox_events ( rulebookName, ruleName, state, durationMs, timestamp ) VALUES ( :rulebookName, :ruleName, :state, :durationMs, :timestamp )", - { - rulebookName : { value: arguments.event.rulebookName, cfsqltype: "varchar" }, - ruleName : { value: arguments.event.ruleName, cfsqltype: "varchar" }, - state : { value: arguments.event.state, cfsqltype: "varchar" }, - durationMs : { value: arguments.event.durationMs, cfsqltype: "double" }, - timestamp : { value: arguments.event.timestamp, cfsqltype: "varchar" } - }, - { datasource: variables.datasourceName } - ) + if( !canAttempt() ){ + return + } + + if( !variables.schemaReady && !ensureSchema() ){ + return + } + + try{ + runSql( + "INSERT INTO rulebox_events ( rulebookName, ruleName, state, durationMs, timestamp ) VALUES ( :rulebookName, :ruleName, :state, :durationMs, :timestamp )", + { + rulebookName : { value: arguments.event.rulebookName, cfsqltype: "varchar" }, + ruleName : { value: arguments.event.ruleName, cfsqltype: "varchar" }, + state : { value: arguments.event.state, cfsqltype: "varchar" }, + durationMs : { value: arguments.event.durationMs, cfsqltype: "double" }, + timestamp : { value: arguments.event.timestamp, cfsqltype: "varchar" } + } + ) + } catch( any e ){ + recordFailure( "#e.message# #e.detail#" ) + return + } + + recordSuccess() + if( shouldPrune() ){ + prune() + } + } + + /** + * The current time in milliseconds, from the injected clock when there is one. + */ + private numeric function nowMillis(){ + return isNull( variables.clock ) ? getTickCount() : variables.clock() } + /** + * Execute SQL through the injected runner when there is one, else queryExecute() on the configured datasource. + * + * @sql The SQL statement + * @params Query parameters + * @options Extra options for the injected runner (queryExecute always uses the configured datasource) + * + * @return The query result, or whatever the injected runner returns + */ + private any function runSql( required string sql, struct params={}, struct options={} ){ + if( !isNull( variables.sqlRunner ) ){ + return variables.sqlRunner( arguments.sql, arguments.params, arguments.options ) + } + return queryExecute( arguments.sql, arguments.params, { datasource: variables.datasourceName } ) + } + + /** + * Return recorded events, newest first. + * + * @filters Optional filters: { rulebookName } + * @limit Max rows to return + * + * @return An array of { rulebookName, ruleName, state, durationMs, timestamp } structs + */ array function queryEvents( struct filters={}, numeric limit=50 ){ var whereClause = arguments.filters.keyExists( "rulebookName" ) ? "WHERE rulebookName = :rulebookName" : "" var params = { limit: { value: arguments.limit, cfsqltype: "integer" } } @@ -78,6 +366,13 @@ class implements="IMetricsStore"{ return q } + /** + * Aggregated stats for one rulebook across all its recorded rules. + * + * @rulebookName The rulebook to summarize + * + * @return { rulebookName, totalEvaluations, countsByState, avgDurationMs, totalDurationMs } + */ struct function queryRuleBookSummary( required string rulebookName ){ var q = queryExecute( " @@ -93,6 +388,14 @@ class implements="IMetricsStore"{ return aggregate( q, { rulebookName: arguments.rulebookName } ) } + /** + * Aggregated stats for a single rule within a rulebook. + * + * @rulebookName The rule's owning rulebook + * @ruleName The rule to summarize + * + * @return { rulebookName, ruleName, totalEvaluations, countsByState, avgDurationMs, minDurationMs, maxDurationMs, lastRunAt } + */ struct function queryRuleMetrics( required string rulebookName, required string ruleName ){ var q = queryExecute( " @@ -125,6 +428,11 @@ class implements="IMetricsStore"{ return summary } + /** + * Every distinct rulebook name that has at least one recorded event. + * + * @return An array of rulebook names + */ array function queryRuleBookNames(){ var q = queryExecute( "SELECT DISTINCT rulebookName FROM rulebox_events ORDER BY rulebookName", @@ -134,6 +442,9 @@ class implements="IMetricsStore"{ return q.map( ( row ) => row.rulebookName ) } + /** + * Clear every recorded event. + */ void function reset(){ queryExecute( "DELETE FROM rulebox_events", {}, { datasource: variables.datasourceName } ) } diff --git a/test-harness/tests/specs/SQLiteMetricsStoreSpec.bx b/test-harness/tests/specs/SQLiteMetricsStoreSpec.bx index b595a0c..3720f8c 100644 --- a/test-harness/tests/specs/SQLiteMetricsStoreSpec.bx +++ b/test-harness/tests/specs/SQLiteMetricsStoreSpec.bx @@ -9,10 +9,19 @@ class extends="tests.resources.BaseSpec"{ function run( testResults, testBox ){ describe( "SQLiteMetricsStore", function(){ + /** + * Visualizer settings as ModuleConfig completes and validates them, with per-spec overrides. + */ + function storeSettings( struct overrides = {} ){ + var visualizer = duplicate( getWireBox().getInstance( dsl="coldbox:moduleSettings:rulebox" ).visualizer ); + visualizer.append( arguments.overrides ); + return { visualizer: visualizer }; + } + function newStore(){ var store = new rulebox.models.metrics.SQLiteMetricsStore(); store.setLogger( getController().getLogBox().getRootLogger() ); - store.setSettings( { visualizer: { datasourceName: "rulebox_visualizer" } } ); + store.setSettings( storeSettings( { datasourceName: "rulebox_visualizer" } ) ); store.onDIComplete(); return store; } @@ -100,6 +109,353 @@ class extends="tests.resources.BaseSpec"{ } ); } ); + + /** + * Pure-logic specs: the SQL runner and the clock are injected, so none of this needs a database + * (and therefore always runs, even where the bx-sqlite driver isn't registered). + */ + describe( "SQLiteMetricsStore hardening (no database)", function(){ + + // Build a store wired to a recording fake runner, a controllable clock and a recording logger + function newUnit( struct visualizer={}, boolean failAtStartup=false ){ + var ctx = { fail: failAtStartup, failDeletes: false, now: 1000000, sql: [], logs: { error: [], warn: [], info: [], debug: [] } }; + var fakeLogger = { + error : ( m ) => ctx.logs.error.append( m ), + warn : ( m ) => ctx.logs.warn.append( m ), + info : ( m ) => ctx.logs.info.append( m ), + debug : ( m ) => ctx.logs.debug.append( m ) + }; + var settings = storeSettings( { datasourceName: "unit_ds" } ); + settings.visualizer.append( visualizer ); + + var store = new rulebox.models.metrics.SQLiteMetricsStore(); + store.setLogger( fakeLogger ); + store.setSettings( settings ); + store.setClock( () => ctx.now ); + store.setSqlRunner( ( sql, params, options ) => { + ctx.sql.append( { sql: sql, params: params } ); + if( ctx.fail || ( ctx.failDeletes && left( trim( sql ), 6 ) == "DELETE" ) ){ + throw( type="UnitTest", message="simulated database failure" ); + } + } ); + store.onDIComplete(); + return { store: store, ctx: ctx }; + } + + function countSql( ctx, verb ){ + return ctx.sql.filter( ( c ) => left( trim( c.sql ), len( verb ) ) == verb ).len(); + } + + function anUnitEvent( ruleName="r1" ){ + return { rulebookName: "unit", ruleName: ruleName, state: "EXECUTED", durationMs: 1, timestamp: "2026-01-01T00:00:00" }; + } + + it( "creates the table and the (rulebookName, ruleName, id) index on startup", function(){ + var u = newUnit(); + + expect( u.store.getSchemaReady() ).toBeTrue(); + expect( u.ctx.sql ).toHaveLength( 2 ); + expect( u.ctx.sql[ 1 ].sql ).toInclude( "CREATE TABLE IF NOT EXISTS rulebox_events" ); + expect( u.ctx.sql[ 2 ].sql ).toInclude( "CREATE INDEX IF NOT EXISTS" ); + expect( u.ctx.sql[ 2 ].sql ).toInclude( "rulebox_events ( rulebookName, ruleName, id )" ); + } ); + + it( "remembers a failed schema create and re-attempts it before the first insert", function(){ + var u = newUnit( failAtStartup=true ); + expect( u.store.getSchemaReady() ).toBeFalse(); + expect( u.ctx.logs.warn ).toHaveLength( 1 ); + + u.ctx.fail = false; + u.ctx.sql = []; + u.store.recordEvent( anUnitEvent() ); + + expect( u.store.getSchemaReady() ).toBeTrue(); + expect( u.ctx.sql[ 1 ].sql ).toInclude( "CREATE TABLE IF NOT EXISTS" ); + expect( u.ctx.sql[ u.ctx.sql.len() ].sql ).toInclude( "INSERT INTO rulebox_events" ); + expect( countSql( u.ctx, "INSERT" ) ).toBe( 1 ); + } ); + + it( "never lets a database failure escape recordEvent", function(){ + var u = newUnit(); + u.ctx.fail = true; + + for( var i = 1; i <= 20; i++ ){ + u.store.recordEvent( anUnitEvent() ); + } + + expect( true ).toBeTrue(); + } ); + + it( "opens the circuit after N consecutive failures and logs exactly one error", function(){ + var u = newUnit( { circuitBreakerThreshold: 3 } ); + u.ctx.fail = true; + + u.store.recordEvent( anUnitEvent() ); + u.store.recordEvent( anUnitEvent() ); + expect( u.store.getCircuitOpen() ).toBeFalse(); + expect( u.ctx.logs.error ).toBeEmpty(); + + u.store.recordEvent( anUnitEvent() ); + expect( u.store.getCircuitOpen() ).toBeTrue(); + expect( u.ctx.logs.error ).toHaveLength( 1 ); + expect( u.ctx.logs.error[ 1 ] ).toInclude( "simulated database failure" ); + } ); + + it( "is a no-op against the database while the circuit is open", function(){ + var u = newUnit( { circuitBreakerThreshold: 2 } ); + u.ctx.fail = true; + u.store.recordEvent( anUnitEvent() ); + u.store.recordEvent( anUnitEvent() ); + expect( u.store.getCircuitOpen() ).toBeTrue(); + var attempts = u.ctx.sql.len(); + + for( var i = 1; i <= 50; i++ ){ + u.store.recordEvent( anUnitEvent() ); + } + + expect( u.ctx.sql ).toHaveLength( attempts ); + expect( u.ctx.logs.error ).toHaveLength( 1 ); + } ); + + it( "stays shut until the cool-down elapses, then recovers on a successful trial with one info log", function(){ + var u = newUnit( { circuitBreakerThreshold: 2, circuitBreakerCooldownSeconds: 60 } ); + u.ctx.fail = true; + u.store.recordEvent( anUnitEvent() ); + u.store.recordEvent( anUnitEvent() ); + expect( u.store.getCircuitOpen() ).toBeTrue(); + + u.ctx.fail = false; + u.ctx.now += 59999; + var before = u.ctx.sql.len(); + u.store.recordEvent( anUnitEvent() ); + expect( u.ctx.sql ).toHaveLength( before ); + expect( u.store.getCircuitOpen() ).toBeTrue(); + + u.ctx.now += 1; + u.store.recordEvent( anUnitEvent() ); + expect( countSql( u.ctx, "INSERT" ) ).toBe( 3 ); + expect( u.store.getCircuitOpen() ).toBeFalse(); + expect( u.ctx.logs.info ).toHaveLength( 1 ); + + u.store.recordEvent( anUnitEvent() ); + expect( countSql( u.ctx, "INSERT" ) ).toBe( 4 ); + expect( u.ctx.logs.info ).toHaveLength( 1 ); + } ); + + it( "lets only one trial through per cool-down and stays open (quietly) when the trial fails", function(){ + var u = newUnit( { circuitBreakerThreshold: 2, circuitBreakerCooldownSeconds: 60 } ); + u.ctx.fail = true; + u.store.recordEvent( anUnitEvent() ); + u.store.recordEvent( anUnitEvent() ); + var attempts = u.ctx.sql.len(); + + u.ctx.now += 60000; + u.store.recordEvent( anUnitEvent() ); + u.store.recordEvent( anUnitEvent() ); + u.store.recordEvent( anUnitEvent() ); + + expect( u.ctx.sql ).toHaveLength( attempts + 1 ); + expect( u.store.getCircuitOpen() ).toBeTrue(); + expect( u.ctx.logs.error ).toHaveLength( 1 ); + + u.ctx.now += 60000; + u.store.recordEvent( anUnitEvent() ); + expect( u.ctx.sql ).toHaveLength( attempts + 2 ); + } ); + + it( "only counts consecutive failures: a success resets the count", function(){ + var u = newUnit( { circuitBreakerThreshold: 3 } ); + + u.ctx.fail = true; + u.store.recordEvent( anUnitEvent() ); + u.store.recordEvent( anUnitEvent() ); + u.ctx.fail = false; + u.store.recordEvent( anUnitEvent() ); + u.ctx.fail = true; + u.store.recordEvent( anUnitEvent() ); + u.store.recordEvent( anUnitEvent() ); + + expect( u.store.getCircuitOpen() ).toBeFalse(); + expect( u.ctx.logs.error ).toBeEmpty(); + } ); + + it( "uses the threshold of 5 that ModuleConfig fills in", function(){ + var u = newUnit( {} ); + u.ctx.fail = true; + + for( var i = 1; i <= 4; i++ ){ + u.store.recordEvent( anUnitEvent() ); + } + expect( u.store.getCircuitOpen() ).toBeFalse(); + + u.store.recordEvent( anUnitEvent() ); + expect( u.store.getCircuitOpen() ).toBeTrue(); + } ); + + it( "does not throw or log per event when the datasource does not exist (real queryExecute path)", function(){ + var logs = { error: [] }; + var store = new rulebox.models.metrics.SQLiteMetricsStore(); + store.setLogger( { + error : ( m ) => logs.error.append( m ), + warn : ( m ) => {}, + info : ( m ) => {}, + debug : ( m ) => {} + } ); + store.setSettings( storeSettings( { datasourceName: "rulebox_no_such_datasource" } ) ); + store.onDIComplete(); + + for( var i = 1; i <= 25; i++ ){ + store.recordEvent( anUnitEvent() ); + } + + expect( store.getCircuitOpen() ).toBeTrue(); + expect( logs.error ).toHaveLength( 1 ); + } ); + + it( "prunes once per pruneEvery inserts, not on every insert", function(){ + var u = newUnit( { retentionDays: 0, maxStoredEvents: 10 } ); + u.store.setPruneEvery( 5 ); + + for( var i = 1; i <= 4; i++ ){ + u.store.recordEvent( anUnitEvent() ); + } + expect( countSql( u.ctx, "DELETE" ) ).toBe( 0 ); + + u.store.recordEvent( anUnitEvent() ); + expect( countSql( u.ctx, "DELETE" ) ).toBe( 1 ); + + for( i = 1; i <= 5; i++ ){ + u.store.recordEvent( anUnitEvent() ); + } + expect( countSql( u.ctx, "DELETE" ) ).toBe( 2 ); + expect( countSql( u.ctx, "INSERT" ) ).toBe( 10 ); + } ); + + it( "never prunes when both retentionDays and maxStoredEvents are 0", function(){ + var u = newUnit( { retentionDays: 0, maxStoredEvents: 0 } ); + u.store.setPruneEvery( 2 ); + + for( var i = 1; i <= 20; i++ ){ + u.store.recordEvent( anUnitEvent() ); + } + + expect( countSql( u.ctx, "DELETE" ) ).toBe( 0 ); + } ); + + it( "builds a retention DELETE per enabled limit", function(){ + var u = newUnit( { retentionDays: 30, maxStoredEvents: 500 } ); + + var statements = u.store.buildPruneStatements( createDateTime( 2026, 2, 1, 12, 0, 0 ) ); + + expect( statements ).toHaveLength( 2 ); + expect( statements[ 1 ].sql ).toInclude( "DELETE FROM rulebox_events WHERE id <=" ); + expect( statements[ 1 ].params.maxEvents.value ).toBe( 500 ); + expect( statements[ 2 ].sql ).toInclude( "DELETE FROM rulebox_events WHERE timestamp <" ); + expect( statements[ 2 ].params.cutoff.value ).toBe( "2026-01-02T12:00:00" ); + + var onlyDays = newUnit( { retentionDays: 7, maxStoredEvents: 0 } ).store.buildPruneStatements(); + expect( onlyDays ).toHaveLength( 1 ); + expect( onlyDays[ 1 ].sql ).toInclude( "timestamp <" ); + } ); + + it( "treats a failing prune as non-fatal and does not trip the breaker", function(){ + var u = newUnit( { retentionDays: 0, maxStoredEvents: 10, circuitBreakerThreshold: 2 } ); + u.store.setPruneEvery( 1 ); + u.ctx.failDeletes = true; + + for( var i = 1; i <= 10; i++ ){ + u.store.recordEvent( anUnitEvent() ); + } + + expect( u.store.getCircuitOpen() ).toBeFalse(); + expect( countSql( u.ctx, "INSERT" ) ).toBe( 10 ); + expect( u.ctx.logs.error ).toBeEmpty(); + expect( u.ctx.logs.warn ).toHaveLength( 10 ); + } ); + + } ); + + /** + * Real bx-sqlite round trips for the new behavior; skipped, like the specs above, where the + * driver isn't registered. + */ + describe( "SQLiteMetricsStore hardening (SQLite)", function(){ + + function newTunedStore( struct visualizer ){ + var settings = storeSettings( { datasourceName: "rulebox_visualizer" } ); + settings.visualizer.append( arguments.visualizer ); + var store = new rulebox.models.metrics.SQLiteMetricsStore(); + store.setLogger( getController().getLogBox().getRootLogger() ); + store.setSettings( settings ); + store.onDIComplete(); + store.reset(); + return store; + } + + beforeEach( function(){ + variables.storeUnavailable = ""; + try{ + newTunedStore( {} ); + } catch( any e ){ + variables.storeUnavailable = "bx-sqlite driver is not registered with BoxLang's DatasourceService in this environment: #e.message#" + } + } ); + + it( "creates the (rulebookName, ruleName, id) index", function(){ + if( len( variables.storeUnavailable ) ){ + skip( variables.storeUnavailable ); + return; + } + newTunedStore( {} ); + + var indexes = queryExecute( + "SELECT name FROM sqlite_master WHERE type = 'index' AND tbl_name = 'rulebox_events'", + {}, + { datasource: "rulebox_visualizer", returnType: "array" } + ).map( ( row ) => row.name ); + + expect( indexes ).toInclude( "idx_rulebox_events_rule" ); + } ); + + it( "keeps only the newest maxStoredEvents rows once the prune cadence is reached", function(){ + if( len( variables.storeUnavailable ) ){ + skip( variables.storeUnavailable ); + return; + } + var store = newTunedStore( { retentionDays: 0, maxStoredEvents: 3 } ); + store.setPruneEvery( 5 ); + + for( var i = 1; i <= 5; i++ ){ + store.recordEvent( { rulebookName: "sqliteTest", ruleName: "r#i#", state: "EXECUTED", durationMs: 1, timestamp: "2026-01-01T00:00:0#i#" } ); + } + + var events = store.queryEvents( filters={ rulebookName: "sqliteTest" } ); + expect( events ).toHaveLength( 3 ); + expect( events.map( ( e ) => e.ruleName ).toList() ).toBe( "r5,r4,r3" ); + } ); + + it( "deletes events older than retentionDays on the prune cadence", function(){ + if( len( variables.storeUnavailable ) ){ + skip( variables.storeUnavailable ); + return; + } + var store = newTunedStore( { retentionDays: 30, maxStoredEvents: 0 } ); + store.setPruneEvery( 5 ); + var recent = dateTimeFormat( now(), "yyyy-MM-dd'T'HH:mm:ss" ); + + for( var i = 1; i <= 3; i++ ){ + store.recordEvent( { rulebookName: "sqliteTest", ruleName: "old#i#", state: "EXECUTED", durationMs: 1, timestamp: "2000-01-01T00:00:00" } ); + } + for( i = 1; i <= 2; i++ ){ + store.recordEvent( { rulebookName: "sqliteTest", ruleName: "new#i#", state: "EXECUTED", durationMs: 1, timestamp: recent } ); + } + + var events = store.queryEvents( filters={ rulebookName: "sqliteTest" } ); + expect( events ).toHaveLength( 2 ); + expect( events.map( ( e ) => e.ruleName ).toList() ).toBe( "new2,new1" ); + } ); + + } ); } } diff --git a/test-harness/tests/specs/VisualizerSettingsSpec.bx b/test-harness/tests/specs/VisualizerSettingsSpec.bx index 0e70dc0..c856c5f 100644 --- a/test-harness/tests/specs/VisualizerSettingsSpec.bx +++ b/test-harness/tests/specs/VisualizerSettingsSpec.bx @@ -95,6 +95,11 @@ class extends="tests.resources.BaseSpec"{ { setting: { enabled: "maybe" }, key: "visualizer.enabled" }, { setting: { enabled: true, metricsStore: " " }, key: "visualizer.metricsStore" }, { setting: { enabled: true, datasourceName: {} }, key: "visualizer.datasourceName" }, + { setting: { enabled: true, circuitBreakerThreshold: "lots" }, key: "visualizer.circuitBreakerThreshold" }, + { setting: { enabled: true, circuitBreakerThreshold: 0 }, key: "visualizer.circuitBreakerThreshold" }, + { setting: { enabled: true, circuitBreakerCooldownSeconds: "x" }, key: "visualizer.circuitBreakerCooldownSeconds" }, + { setting: { enabled: true, retentionDays: -1 }, key: "visualizer.retentionDays" }, + { setting: { enabled: true, maxStoredEvents: 1.5 }, key: "visualizer.maxStoredEvents" }, { setting: { enabled: true, maxStreams: "lots" }, key: "visualizer.maxStreams" }, { setting: { enabled: true, maxStreams: 0 }, key: "visualizer.maxStreams" }, { setting: { enabled: true, maxStreams: 2.5 }, key: "visualizer.maxStreams" }