Skip to content

Commit b1e3055

Browse files
committed
perf(database): reserve query traces for problems
1 parent 1074b2e commit b1e3055

7 files changed

Lines changed: 34 additions & 15 deletions

File tree

config/database.ts

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -188,6 +188,12 @@ export default {
188188
*/
189189
enabled: env.DB_QUERY_LOGGING_ENABLED ?? true,
190190

191+
/**
192+
* Capture caller stacks for successful fast queries too. Slow and failed
193+
* queries always retain their caller details.
194+
*/
195+
captureAllTraces: env.DB_QUERY_LOGGING_CAPTURE_ALL_TRACES ?? false,
196+
191197
/**
192198
* The threshold in milliseconds to mark a query as slow
193199
*/

docs/guide/query-monitoring.md

Lines changed: 14 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,7 @@ The Query Monitoring system provides comprehensive tools to collect, analyze, an
1111
- **Real-time Query Logging**: Automatically logs all database queries with detailed information
1212
- **Query Analysis**: Analyzes query patterns, identifies slow queries, and suggests optimizations
1313
- **Dashboard Interface**: Visual dashboard for monitoring query performance metrics
14-
- **Detailed Query Information**: Displays query details including duration, status, bindings, and more
14+
- **Detailed Query Information**: Displays query details including duration, status, bindings, and caller traces for slow or failed queries
1515
- **Advanced Filtering**: Filter queries by type, status, connection, and more
1616
- **Optimization Suggestions**: Automated recommendations for improving query performance
1717

@@ -27,6 +27,9 @@ export default {
2727
// Enable or disable query logging
2828
enabled: true,
2929

30+
// Also capture caller stacks for successful fast queries
31+
captureAllTraces: false,
32+
3033
// Threshold in milliseconds to mark a query as slow
3134
slowThreshold: 100,
3235

@@ -56,6 +59,7 @@ You can also configure query monitoring using environment variables:
5659

5760
```
5861
DB_QUERY_LOGGING_ENABLED=true
62+
DB_QUERY_LOGGING_CAPTURE_ALL_TRACES=false
5963
DB_QUERY_LOGGING_SLOW_THRESHOLD=100
6064
DB_QUERY_LOGGING_RETENTION_DAYS=7
6165
DB_QUERY_LOGGING_PRUNE_FREQUENCY=24
@@ -103,7 +107,7 @@ The detail view provides comprehensive information about a specific query:
103107
- Full query text and normalized version
104108
- Execution metrics and duration
105109
- Bindings and parameters
106-
- Stack trace and caller information
110+
- Stack trace and caller information for slow or failed queries
107111
- Index usage information
108112
- EXPLAIN plan data
109113
- Optimization suggestions
@@ -135,11 +139,11 @@ Queries are stored in the `query_logs` table with the following structure:
135139
| error | text | Error message if failed |
136140
| executed_at | timestamp | When the query was executed |
137141
| bindings | text | JSON array of query parameters |
138-
| trace | text | Stack trace showing where query was called |
139-
| model | text | Model that executed the query |
140-
| method | text | Method that executed the query |
141-
| file | text | File path where query originated |
142-
| line | integer | Line number where query originated |
142+
| trace | text | Stack trace for a slow or failed query |
143+
| model | text | Model that executed a slow or failed query |
144+
| method | text | Method that executed a slow or failed query |
145+
| file | text | File path where a slow or failed query originated |
146+
| line | integer | Line number where a slow or failed query originated |
143147
| memory_usage | numeric | Memory used during execution |
144148
| rows_affected | integer | Number of rows affected |
145149
| transaction_id | text | Related transaction identifier |
@@ -164,7 +168,9 @@ The system includes a scheduled job (`PruneQueryLogsJob`) that automatically rem
164168

165169
4. **Database Impact**: Be aware that query logging itself adds some overhead. Monitor the performance impact and adjust settings accordingly.
166170

167-
5. **Security**: Query logs may contain sensitive information in bindings. Ensure that access to the query dashboard is properly secured.
171+
5. **Caller Traces**: Slow and failed queries always include caller traces. Enable `captureAllTraces` only when fast-query call sites are worth the additional CPU and storage cost.
172+
173+
6. **Security**: Query logs may contain sensitive information in bindings. Ensure that access to the query dashboard is properly secured.
168174

169175
## Debugging with Query Logs
170176

storage/framework/core/database/src/query-logger.ts

Lines changed: 8 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -293,8 +293,12 @@ async function createQueryLogRecord(
293293
// Get normalized query (replace specific values with placeholders)
294294
const normalizedQuery = normalizeQuery(query) || query
295295

296-
// Extract stack trace and caller information
297-
const { trace, caller } = extractTraceInfo()
296+
// Caller traces are most useful when a query needs investigation. Capturing
297+
// an Error stack for every successful fast query is expensive and inflates
298+
// the log rows that dominate production traffic.
299+
const traceInfo = status === 'completed' && !config.database?.queryLogging?.captureAllTraces
300+
? undefined
301+
: extractTraceInfo()
298302

299303
return {
300304
query,
@@ -305,8 +309,8 @@ async function createQueryLogRecord(
305309
error: error ? String(error) : undefined,
306310
executed_at: sqlDateTime(),
307311
bindings,
308-
trace,
309-
...caller,
312+
trace: traceInfo?.trace,
313+
...(traceInfo?.caller ?? {}),
310314
memory_usage: memoryUsage().heapUsed / 1024 / 1024, // in MB
311315
}
312316
}

storage/framework/core/database/tests/fixtures/query-logger-dispatch.ts

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -160,12 +160,12 @@ try {
160160
{ query: { sql: analyzedSql }, queryDurationMillis: 101 },
161161
]
162162
await Promise.all((slowFirst ? events.reverse() : events).map(logQuery))
163-
const records = await db.unsafe('SELECT query, status, affected_tables, tags FROM query_logs WHERE query IN (?, ?)', [ordinarySql, analyzedSql]).execute()
163+
const records = await db.unsafe('SELECT query, status, affected_tables, tags, trace FROM query_logs WHERE query IN (?, ?)', [ordinarySql, analyzedSql]).execute()
164164
const ordinary = records.find(row => row.query === ordinarySql)
165165
const analyzed = records.find(row => row.query === analyzedSql)
166-
if (records.length !== 2 || ordinary?.status !== 'completed' || ordinary.affected_tables !== null || ordinary.tags !== null)
166+
if (records.length !== 2 || ordinary?.status !== 'completed' || ordinary.affected_tables !== null || ordinary.tags !== null || ordinary.trace !== null)
167167
throw new Error('Concurrent ordinary query diagnostics changed')
168-
if (analyzed?.status !== 'slow' || analyzed.affected_tables !== '["query_logger_fixture"]' || analyzed.tags !== '["SELECT","table:query_logger_fixture"]')
168+
if (analyzed?.status !== 'slow' || analyzed.affected_tables !== '["query_logger_fixture"]' || analyzed.tags !== '["SELECT","table:query_logger_fixture"]' || !String(analyzed.trace).includes('query-logger-dispatch.ts'))
169169
throw new Error('Concurrent slow query analysis was lost')
170170
}
171171
}

storage/framework/core/database/tests/fixtures/query-trace.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@ initializeDbConfig({
1111
config.database.queryLogging = {
1212
...config.database.queryLogging,
1313
enabled: true,
14+
captureAllTraces: true,
1415
excludedQueries: [],
1516
analysis: { ...config.database.queryLogging?.analysis, enabled: false },
1617
}

storage/framework/core/env/src/types.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -142,6 +142,7 @@ export interface FrameworkEnv {
142142
DB_READ_HOSTS: string | undefined
143143
DB_READ_AUTO_ROUTE: boolean | undefined
144144
DB_QUERY_LOGGING_ENABLED: boolean | undefined
145+
DB_QUERY_LOGGING_CAPTURE_ALL_TRACES: boolean | undefined
145146
DB_QUERY_LOGGING_SLOW_THRESHOLD: number | undefined
146147
DB_QUERY_LOGGING_RETENTION_DAYS: number | undefined
147148
DB_QUERY_LOGGING_PRUNE_FREQUENCY: number | undefined

storage/framework/defaults/ai/skills/stacks-database/SKILL.md

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -259,6 +259,7 @@ Entity-centric API for single-table design:
259259
migrationLocks: 'migration_locks',
260260
queryLogging: {
261261
enabled: true,
262+
captureAllTraces: false, // slow and failed queries always keep traces
262263
slowThreshold: 100, // ms
263264
retention: 7, // days
264265
pruneFrequency: 24, // hours

0 commit comments

Comments
 (0)