@@ -126,14 +126,23 @@ const DRIVER_REBUILD_MIN_INTERVAL_MS = 30 * 1000;
126126const MAX_CONSECUTIVE_PROBE_FAILURES = 3 ;
127127
128128/**
129- * How long those failures must span before the driver is given up.
129+ * How long those failures must span before the driver is given up, and how long
130+ * one of them stays on the record.
130131 *
131132 * The count alone is not a duration: under load three concurrent probes can
132133 * fail inside the same blink of a dependency. Requiring both keeps a burst from
133134 * tearing down a working pool while still bounding how long a refusal can be
134135 * ignored.
136+ *
137+ * Minutes rather than seconds because a probe failure is not evidence about the
138+ * cached connection — it is evidence about whatever the factory had to reach to
139+ * answer. A secret store restarting, a token endpoint returning 503, a DNS blip
140+ * inside the factory: in every one of those the cached credential is untouched
141+ * and still valid, and giving the pool up makes a dependency's outage into a
142+ * query outage. A credential that has genuinely stopped working is not urgent
143+ * to the second, so the bar is set where a dependency can restart under it.
135144 */
136- const PROBE_FAILURE_GRACE_MS = 30 * 1000 ;
145+ const PROBE_FAILURE_GRACE_MS = 5 * 60 * 1000 ;
137146
138147/**
139148 * What a cached driver was built from. `null` on either fingerprint means
@@ -146,10 +155,20 @@ type DriverOrigin = {
146155 expiresAt : number | undefined ;
147156} ;
148157
149- /** Consecutive probe failures for one alias set, and when they started. */
158+ /**
159+ * Probe failures for one alias set inside one rolling window: how many, when
160+ * the window opened, and when it was last extended.
161+ *
162+ * `lastFailureAt` is what makes the window rolling. Probes are only issued when
163+ * the security context fingerprint changes, so in a quiet deployment two of
164+ * them can be hours apart with nothing in between to clear the count — and
165+ * three unrelated flakes on three different days are not a sustained refusal,
166+ * however they look to a counter that only ever goes up.
167+ */
150168type DriverProbeFailures = {
151169 count : number ;
152170 firstFailureAt : number ;
171+ lastFailureAt : number ;
153172} ;
154173
155174/** A `driverFactory` result together with the context that produced it. */
@@ -158,9 +177,19 @@ type DriverFactoryResult = {
158177 securityContextFingerprint : string | null ;
159178} ;
160179
161- /** Why a cached driver is being replaced , for the operator reading the log. */
180+ /** Why a cached driver was found stale , for the operator reading the log. */
162181type DriverStalenessReason = 'configuration change' | 'lifetime elapsed' ;
163182
183+ /**
184+ * Every reason a cached driver is replaced. A refusal is not a staleness
185+ * verdict — the factory never produced a configuration to compare — but it
186+ * tears down the same connection pool, so it is counted and rate-limited
187+ * alongside the verdicts rather than slipping past both brakes.
188+ */
189+ type DriverReplacementReason =
190+ | DriverStalenessReason
191+ | 'repeated staleness check failures' ;
192+
164193/**
165194 * The verdict on a cached driver. `factoryResult` is present only when the
166195 * probe already resolved one, so the rebuild does not call the factory twice;
@@ -840,6 +869,60 @@ export class CubejsServerCore {
840869 */
841870 const rebuildKey = aliasedKeys [ 0 ] ;
842871
872+ /**
873+ * Count a replacement against the alias set's rebuild history, open a
874+ * suppression window on it, and report it.
875+ *
876+ * Both paths that tear a pool down come through here — a configuration
877+ * the factory changed, and a factory that will no longer produce one.
878+ * They cost the same thing, so they are bounded by the same state: a
879+ * replacement that skipped this would rebuild straight past the interval
880+ * that exists to stop pool churn, and never reach the diagnostic that
881+ * names it.
882+ */
883+ const recordDriverRebuild = ( reason : DriverReplacementReason , warning : string ) => {
884+ // Re-read rather than reusing what was captured before the staleness
885+ // probe awaited: reaching here means no concurrent rebuild landed, but
886+ // the count is the one piece of state that would silently lose an
887+ // increment if that ever stopped being true.
888+ const state = driverRebuilds [ rebuildKey ]
889+ || { count : 0 , lastRebuildAt : 0 , suppressionReported : false } ;
890+
891+ state . count += 1 ;
892+ state . lastRebuildAt = Date . now ( ) ;
893+ state . suppressionReported = false ;
894+ driverRebuilds [ rebuildKey ] = state ;
895+
896+ // Carries `warning` so it survives the default log level: a plain-params
897+ // message matches no allowlist in `prodLogger`/`devLogger` and is
898+ // dropped below `trace`. Tearing down a connection pool is an event an
899+ // operator needs to be able to correlate against, and the threshold
900+ // message below arrives too late to reconstruct the first rebuilds.
901+ this . logger ( 'Rebuilding driver' , {
902+ dataSource,
903+ preAggregations,
904+ rebuildCount : state . count ,
905+ reason,
906+ warning,
907+ } ) ;
908+
909+ // A credential rotation rebuilds a handful of times a day. Rebuilding
910+ // this often means the orchestrator id does not partition by whatever
911+ // the factory reads, so contexts that need different connections keep
912+ // displacing each other's driver — or that the factory is not resolving
913+ // reliably enough to keep any connection.
914+ if ( state . count === DRIVER_REBUILD_WARN_THRESHOLD ) {
915+ this . logger ( 'Driver rebuilt repeatedly' , {
916+ dataSource,
917+ rebuildCount : state . count ,
918+ warning : 'Driver keeps being replaced for one orchestrator. '
919+ + 'contextToOrchestratorId likely does not distinguish the contexts '
920+ + 'driverFactory returns different connections for, or driverFactory '
921+ + 'is not resolving a configuration reliably.' ,
922+ } ) ;
923+ }
924+ } ;
925+
843926 // Already resolved by the staleness check below, so the factory is not
844927 // asked twice for the same rebuild.
845928 let resolvedFactoryResult : DriverFactoryResult | undefined ;
@@ -921,13 +1004,22 @@ export class CubejsServerCore {
9211004 return cached ;
9221005 }
9231006
924- const failures = driverProbeFailures [ rebuildKey ]
925- || { count : 0 , firstFailureAt : Date . now ( ) } ;
1007+ const now = Date . now ( ) ;
1008+ const previousFailures = driverProbeFailures [ rebuildKey ] ;
1009+
1010+ // A rolling window, not a running total. Probes are only issued when
1011+ // the context changes, so a record that is never re-based would add
1012+ // up occasional flakes weeks apart and read them as one outage.
1013+ const failures = previousFailures
1014+ && now - previousFailures . lastFailureAt < PROBE_FAILURE_GRACE_MS
1015+ ? previousFailures
1016+ : { count : 0 , firstFailureAt : now , lastFailureAt : now } ;
9261017
9271018 failures . count += 1 ;
1019+ failures . lastFailureAt = now ;
9281020 driverProbeFailures [ rebuildKey ] = failures ;
9291021
930- const failingForMs = Date . now ( ) - failures . firstFailureAt ;
1022+ const failingForMs = now - failures . firstFailureAt ;
9311023
9321024 // Transient, as far as anything here can tell. Reuse, exactly as
9331025 // before this bound existed.
@@ -938,17 +1030,15 @@ export class CubejsServerCore {
9381030 return cached ;
9391031 }
9401032
941- this . logger ( 'Releasing driver after repeated staleness check failures' , {
942- dataSource,
943- preAggregations,
944- failureCount : failures . count ,
945- warning : 'driverFactory has failed every staleness check for '
946- + `${ Math . round ( failingForMs / 1000 ) } s. Releasing the connection it `
947- + 'built rather than serving queries on a configuration it will no '
948- + 'longer produce; the next request calls the factory itself, so a '
949- + 'factory that fails closed on an unusable credential surfaces its '
950- + 'own error.' ,
951- } ) ;
1033+ recordDriverRebuild (
1034+ 'repeated staleness check failures' ,
1035+ `driverFactory has failed every staleness check for ${
1036+ Math . round ( failingForMs / 1000 )
1037+ } s. Releasing the connection it built rather than serving queries on `
1038+ + 'a configuration it will no longer produce; the next request calls '
1039+ + 'the factory itself, so a factory that fails closed on an unusable '
1040+ + 'credential surfaces its own error.' ,
1041+ ) ;
9521042
9531043 delete driverProbeFailures [ rebuildKey ] ;
9541044 replaceCachedDriver ( cached ) ;
@@ -959,48 +1049,10 @@ export class CubejsServerCore {
9591049 // Opens a fresh suppression window, so the next configuration change
9601050 // for this alias set waits it out rather than tearing down the pool
9611051 // this rebuild is about to stand up.
962- //
963- // Re-read rather than reusing what was captured before the staleness
964- // probe awaited: reaching here means no concurrent rebuild landed, but
965- // the count is the one piece of state that would silently lose an
966- // increment if that ever stopped being true.
967- const state = driverRebuilds [ rebuildKey ]
968- || { count : 0 , lastRebuildAt : 0 , suppressionReported : false } ;
969-
970- state . count += 1 ;
971- state . lastRebuildAt = Date . now ( ) ;
972- state . suppressionReported = false ;
973- driverRebuilds [ rebuildKey ] = state ;
974-
975- const rebuildCount = state . count ;
976-
977- // Carries `warning` so it survives the default log level: a
978- // plain-params message matches no allowlist in
979- // `prodLogger`/`devLogger` and is dropped below `trace`. Tearing down
980- // a connection pool is an event an operator needs to be able to
981- // correlate against, and the threshold message below arrives too late
982- // to reconstruct the first rebuilds.
983- this . logger ( 'Rebuilding driver' , {
984- dataSource,
985- preAggregations,
986- rebuildCount,
987- reason : staleness . reason ,
988- warning : `Replacing the connection — ${ staleness . reason } .` ,
989- } ) ;
990-
991- // A credential rotation rebuilds a handful of times a day. Rebuilding
992- // this often means the orchestrator id does not partition by whatever
993- // the factory reads, so contexts that need different connections keep
994- // displacing each other's driver.
995- if ( rebuildCount === DRIVER_REBUILD_WARN_THRESHOLD ) {
996- this . logger ( 'Driver rebuilt repeatedly' , {
997- dataSource,
998- rebuildCount,
999- warning : 'Driver configuration keeps changing for one orchestrator. '
1000- + 'contextToOrchestratorId likely does not distinguish the contexts '
1001- + 'driverFactory returns different connections for.' ,
1002- } ) ;
1003- }
1052+ recordDriverRebuild (
1053+ staleness . reason ,
1054+ `Replacing the connection — ${ staleness . reason } .` ,
1055+ ) ;
10041056
10051057 delete driverProbeFailures [ rebuildKey ] ;
10061058 replaceCachedDriver ( cached ) ;
@@ -1049,7 +1101,7 @@ export class CubejsServerCore {
10491101 ? driverConfigFingerprint ( factoryConfig )
10501102 : null ;
10511103 origin . expiresAt = factoryConfig
1052- ? parseDriverExpiry ( factoryConfig . expiresAt )
1104+ ? this . resolveBuiltDriverExpiry ( factoryConfig , dataSource )
10531105 : undefined ;
10541106
10551107 driver = await this . createDriverFromFactoryResult (
@@ -1365,6 +1417,48 @@ export class CubejsServerCore {
13651417 }
13661418 }
13671419
1420+ /**
1421+ * The lifetime to hold a driver to, given the configuration it was just built
1422+ * from — and `undefined` where that configuration named a deadline that had
1423+ * already passed.
1424+ *
1425+ * Rebuilding cannot fix a deadline the factory keeps re-asserting. Honouring
1426+ * one would find the new driver stale the moment its suppression window
1427+ * closed, tear down a pool it had just stood up, and resolve the same elapsed
1428+ * deadline again, for the life of the process. A driver built from an expired
1429+ * configuration is no worse than the one it replaced, so the connection is
1430+ * kept and the lifetime dropped — the operator gets a warning naming the
1431+ * field rather than churn that never resolves.
1432+ *
1433+ * The documented recipe does not reach this: its `accessToken()` withholds a
1434+ * token that is already near expiry, so the configuration changes to the
1435+ * service account, which names no lifetime, and converges. A factory passing
1436+ * the provider's `accessTokenExpiresAt` straight through does reach it.
1437+ */
1438+ protected resolveBuiltDriverExpiry (
1439+ config : DriverConfig ,
1440+ dataSource : string ,
1441+ ) : number | undefined {
1442+ const expiresAt = parseDriverExpiry ( config . expiresAt ) ;
1443+
1444+ if ( expiresAt === undefined || Date . now ( ) < expiresAt ) {
1445+ return expiresAt ;
1446+ }
1447+
1448+ this . logger ( 'Driver configuration expired on arrival' , {
1449+ dataSource,
1450+ expiresAt : new Date ( expiresAt ) . toISOString ( ) ,
1451+ warning : 'driverFactory returned a configuration whose expiresAt has '
1452+ + 'already passed. Using the connection anyway and ignoring the '
1453+ + 'lifetime: replacing a driver cannot move a deadline the factory '
1454+ + 'keeps re-asserting, and honouring it would rebuild the pool for the '
1455+ + 'life of the process. expiresAt must state when the credential being '
1456+ + 'returned stops being usable, in the future.' ,
1457+ } ) ;
1458+
1459+ return undefined ;
1460+ }
1461+
13681462 /**
13691463 * Decide whether a cached driver still reflects what `driverFactory` would
13701464 * resolve for the current request context.
@@ -1471,9 +1565,11 @@ export class CubejsServerCore {
14711565 // is excluded from the fingerprint, so a credential re-issued with the
14721566 // same value and a later expiry compares equal. Carrying the new deadline
14731567 // over is what keeps that from rebuilding on the old one, once per window,
1474- // forever.
1568+ // forever. Guarded like the build path, because a factory re-asserting an
1569+ // elapsed deadline would otherwise reinstate it here on the next context
1570+ // change, reopening the loop that guard exists to close.
14751571 if ( config ) {
1476- origin . expiresAt = parseDriverExpiry ( config . expiresAt ) ;
1572+ origin . expiresAt = this . resolveBuiltDriverExpiry ( config , context . dataSource ) ;
14771573 }
14781574
14791575 return { stale : false } ;
0 commit comments