Add Metrics details and fix explain

api-client/deno.json

@@ -3,7 +3,7 @@
     "@preact/signals": "npm:@preact/signals@^2.9.0"
   },
   "name": "@01edu/api-client",
-  "version": "0.2.1",
+  "version": "0.2.2",
   "license": "MIT",
   "exports": { ".": "./mod.ts" },
   "compilerOptions": {

api/deno.json

@@ -4,7 +4,7 @@
     "@std/http": "jsr:@std/http@^1.0.25"
   },
   "name": "@01edu/api",
-  "version": "0.2.1",
+  "version": "0.2.2",
   "license": "MIT",
   "exports": {
     "./context": "./context.ts",

api/dev.ts

@@ -73,7 +73,25 @@ export const createQueryMetricsDevRoute = (metrics: Metric[]) =>
         query: STR('The SQL query text'),
         count: NUM('How many times the query has run'),
         duration: NUM('Total time spent running the query in milliseconds'),
-        explain: STR('The SQL explain text'),
+        max: NUM('Longest single query execution in milliseconds'),
+        explain: ARR(
+          OBJ({
+            id: NUM('Query plan node id'),
+            parent: NUM('Parent query plan node id'),
+            detail: STR('Human-readable query plan detail'),
+          }),
+          'SQLite EXPLAIN QUERY PLAN rows',
+        ),
+        status: OBJ({
+          fullscanStep: NUM('Number of full table scan steps'),
+          sort: NUM('Number of sort operations'),
+          autoindex: NUM('Rows inserted into transient auto-indices'),
+          vmStep: NUM('Number of virtual machine operations'),
+          reprepare: NUM('Number of automatic statement reprepares'),
+          run: NUM('Number of statement runs'),
+          filterHit: NUM('Bloom filter bypass hits'),
+          filterMiss: NUM('Bloom filter misses'),
+        }, 'SQLite sqlite3_stmt_status counters'),
       }),
       'Collected query metrics',
     ),

db/deno.json

@@ -4,7 +4,7 @@
     "@std/assert": "jsr:@std/assert@^1.0.19"
   },
   "name": "@01edu/db",
-  "version": "0.2.1",
+  "version": "0.2.2",
   "license": "MIT",
   "exports": {
     ".": "./mod.ts",

db/mod.ts

@@ -7,9 +7,10 @@
  */
 
 import { assertEquals } from '@std/assert/equals'
-import { type BindParameters, type BindValue, Database } from '@db/sqlite'
+import { Database } from '@db/sqlite'
+import type { BindParameters, BindValue, Statement } from '@db/sqlite'
 import type { Expand, MatchKeys, UnionToIntersection } from '@01edu/types'
-import type { Metric, Sql } from '@01edu/types/db'
+import type { ExplainRow, Metric, Sql, StatementStatus } from '@01edu/types/db'
 import { respond } from '@01edu/api/response'
 import { APP_ENV, DISABLE_QUERY_METRICS, ENV } from '@01edu/api/env'
 
@@ -410,17 +411,32 @@ export const sql: Sql = <
     value: (params?: P) => stmt.value(params) as T[keyof T][] | undefined,
   }
   if (DISABLE_QUERY_METRICS || !query.startsWith('SELECT ')) return boundStmt
-  const explain = db.prepare(`EXPLAIN QUERY PLAN ${query}`).get()?.detail || ''
-  const m = { query, explain, count: 0, duration: 0 }
+  const explain = db.prepare<ExplainRow>(`EXPLAIN QUERY PLAN ${query}`).all()
+  const m = {
+    query,
+    explain: explain.map(({ parent, id, detail }) => ({ parent, id, detail })),
+    count: 0,
+    duration: 0,
+    max: 0,
+    get status() {
+      return readStmtStatus(stmt)
+    },
+  }
+
   metrics.push(m)
 
   const withMetrics = <R>(fn: (params?: P) => R) => (params?: P): R => {
     const start = performance.now()
-    const result = fn(params)
-    m.count++
-    m.duration += performance.now() - start
-    return result
+    try {
+      return fn(params)
+    } finally {
+      const elapsed = performance.now() - start
+      m.count++
+      m.duration += elapsed
+      m.max = Math.max(m.max, elapsed)
+    }
   }
+
   return {
     get: withMetrics(boundStmt.get),
     all: withMetrics(boundStmt.all),
@@ -493,3 +509,83 @@ export const sqlCheck = <T extends BindValue | BindParameters>(
   const { value } = sql`SELECT EXISTS(SELECT 1 ${String.raw(query, ...args)})`
   return ((params: T) => value(params)?.[0] === 1)
 }
+
+let readStmtStatus = (
+  _: Statement<Record<string, unknown>>,
+): StatementStatus => ({
+  fullscanStep: 0,
+  sort: 0,
+  autoindex: 0,
+  vmStep: 0,
+  reprepare: 0,
+  run: 0,
+  filterMiss: 0,
+  filterHit: 0,
+})
+
+if (!DISABLE_QUERY_METRICS) {
+  const defaultSqliteLibPath = (): string => {
+    switch (Deno.build.os) {
+      case 'darwin':
+        return 'libsqlite3.dylib'
+      case 'linux':
+        return 'libsqlite3.so'
+      case 'windows':
+        return 'sqlite3.dll'
+      default:
+        throw new Error(`Unsupported OS: ${Deno.build.os}`)
+    }
+  }
+
+  const sqliteLibPath = Deno.env.get('SQLITE3_LIB_PATH') ??
+    defaultSqliteLibPath()
+  const lib = Deno.dlopen(sqliteLibPath, {
+    sqlite3_stmt_status: {
+      parameters: ['pointer', 'i32', 'i32'],
+      result: 'i32',
+    },
+  })
+  const { sqlite3_stmt_status } = lib.symbols
+
+  // These match SQLite's documented SQLITE_STMTSTATUS_* constants.
+  // https://sqlite.org/c3ref/c_stmtstatus_counter.html
+  const SQLITE_STMTSTATUS_FULLSCAN_STEP = 1
+  const SQLITE_STMTSTATUS_SORT = 2
+  const SQLITE_STMTSTATUS_AUTOINDEX = 3
+  const SQLITE_STMTSTATUS_VM_STEP = 4
+  const SQLITE_STMTSTATUS_REPREPARE = 5
+  const SQLITE_STMTSTATUS_RUN = 6
+  const SQLITE_STMTSTATUS_FILTER_MISS = 7
+  const SQLITE_STMTSTATUS_FILTER_HIT = 8
+  const SQLITE_STMTSTATUS_MEMUSED = 99
+
+  type StmtStatusOp =
+    | typeof SQLITE_STMTSTATUS_FULLSCAN_STEP
+    | typeof SQLITE_STMTSTATUS_SORT
+    | typeof SQLITE_STMTSTATUS_AUTOINDEX
+    | typeof SQLITE_STMTSTATUS_VM_STEP
+    | typeof SQLITE_STMTSTATUS_REPREPARE
+    | typeof SQLITE_STMTSTATUS_RUN
+    | typeof SQLITE_STMTSTATUS_FILTER_MISS
+    | typeof SQLITE_STMTSTATUS_FILTER_HIT
+    | typeof SQLITE_STMTSTATUS_MEMUSED
+
+  const stmtStatus = (
+    stmt: Statement<Record<string, unknown>>,
+    op: StmtStatusOp,
+  ): number => sqlite3_stmt_status(stmt.unsafeHandle, op, 0)
+
+  readStmtStatus = (
+    stmt: Statement<Record<string, unknown>>,
+  ): StatementStatus => ({
+    fullscanStep: stmtStatus(stmt, SQLITE_STMTSTATUS_FULLSCAN_STEP),
+    sort: stmtStatus(stmt, SQLITE_STMTSTATUS_SORT),
+    autoindex: stmtStatus(stmt, SQLITE_STMTSTATUS_AUTOINDEX),
+    vmStep: stmtStatus(stmt, SQLITE_STMTSTATUS_VM_STEP),
+    reprepare: stmtStatus(stmt, SQLITE_STMTSTATUS_REPREPARE),
+    run: stmtStatus(stmt, SQLITE_STMTSTATUS_RUN),
+    filterMiss: stmtStatus(stmt, SQLITE_STMTSTATUS_FILTER_MISS),
+    filterHit: stmtStatus(stmt, SQLITE_STMTSTATUS_FILTER_HIT),
+    // memUsed: stmtStatus(stmt, SQLITE_STMTSTATUS_MEMUSED), unsupported for some reason
+  })
+}

types/db.d.ts

@@ -1,22 +1,80 @@
 import type { BindParameters, BindValue } from '@db/sqlite'
 
 /**
- * Type definition for the `sql` template tag function.
- * It allows executing SQL queries with parameter binding and retrieving results in various formats.
+ * Tagged-template helper used to build a SQL statement and execute it later.
+ *
+ * Interpolated `vars` are inserted in the query text. Runtime bind parameters are
+ * provided when calling one of the returned methods (`get`, `all`, `run`, `value`).
+ *
+ * @template T Result row shape returned by `get` and `all`.
+ * @template P Bind parameter format accepted by `@db/sqlite`.
  */
 export type Sql = <
   T extends { [k in string]: unknown } | undefined,
   P extends BindValue | BindParameters | undefined,
 >(sqlArr: TemplateStringsArray, ...vars: unknown[]) => {
+  /** Returns the first matching row, or `undefined` if the query returns no rows. */
   get: (params?: P) => T | undefined
+  /** Returns all matching rows. */
   all: (params?: P) => T[]
+  /** Executes the statement and returns the number of affected rows. */
   run: (params?: P) => number
+  /** Returns the selected row values as an array, or `undefined` when no row is found. */
   value: (params?: P) => T[keyof T][] | undefined
 }
 
+/**
+ * Row shape returned by SQLite `EXPLAIN QUERY PLAN`.
+ *
+ * @see https://sqlite.org/eqp.html
+ */
+export type ExplainRow = {
+  /** Node id in the query plan tree. */
+  id: number
+  /** Parent node id (`0` for top-level nodes). */
+  parent: number
+  /** Human-readable description of the query plan step. */
+  detail: string
+}
+
+/**
+ * Counter values associated with the SQLite sqlite3_stmt_status() interface
+ *
+ * @see https://sqlite.org/c3ref/c_stmtstatus_counter.html
+ */
+export type StatementStatus = {
+  /** This is the number of times that SQLite has stepped forward in a table as part of a full table scan. Large numbers for this counter may indicate opportunities for performance improvement through careful use of indices. */
+  fullscanStep: number
+  /** This is the number of sort operations that have occurred. A non-zero value in this counter may indicate an opportunity to improve performance through careful use of indices. */
+  sort: number
+  /** This is the number of rows inserted into transient indices that were created automatically in order to help joins run faster. A non-zero value in this counter may indicate an opportunity to improve performance by adding permanent indices that do not need to be reinitialized each time the statement is run. */
+  autoindex: number
+  /** This is the number of virtual machine operations executed by the prepared statement if that number is less than or equal to 2147483647. The number of virtual machine operations can be used as a proxy for the total work done by the prepared statement. If the number of virtual machine operations exceeds 2147483647 then the value returned by this statement status code is undefined. */
+  vmStep: number
+  /** This is the number of times that the prepare statement has been automatically regenerated due to schema changes or changes to bound parameters that might affect the query plan. */
+  reprepare: number
+  /** This is the number of times that the prepared statement has been run. A single "run" for the purposes of this counter is one or more calls to sqlite3_step() followed by a call to sqlite3_reset(). The counter is incremented on the first sqlite3_step() call of each cycle. */
+  run: number
+  /** This is the number of times that a join step was bypassed because a Bloom filter returned not-found. */
+  filterHit: number
+  /** The corresponding SQLITE_STMTSTATUS_FILTER_MISS value is the number of times that the Bloom filter returned a find, and thus the join step had to be processed as normal. */
+  filterMiss: number
+}
+
+/**
+ * Aggregated metrics for one tracked SQL query shape.
+ */
 export type Metric = {
+  /** Longest single execution time in milliseconds. */
+  max: number
+  /** SQL query text used as the metric key. */
   query: string
+  /** Number of times the statement has been executed. */
   count: number
+  /** Total accumulated execution time in milliseconds. */
   duration: number
-  explain: string
+  /** Query plan details captured for this statement. */
+  explain: ExplainRow[]
+  /** Sqlite Statement Status counters from sqlite3_stmt_status(). */
+  status: StatementStatus
 }

types/deno.json

@@ -3,7 +3,7 @@
     "@db/sqlite": "jsr:@db/sqlite@^0.13.0"
   },
   "name": "@01edu/types",
-  "version": "0.2.1",
+  "version": "0.2.2",
   "license": "MIT",
   "exports": {
     ".": "./mod.d.ts",