[Experimental] Log queries to the console

.changeset/kind-badgers-watch.md

@@ -0,0 +1,6 @@
+---
+'@powersync/op-sqlite': patch
+'@powersync/web': patch
+---
+
+Log queries to console in debugMode.

packages/attachments/package.json

@@ -39,7 +39,7 @@
   ],
   "scripts": {
     "build": "tsc -b && rollup --config",
-    "build:prod": "tsc -b --sourceMap false && rollup",
+    "build:prod": "tsc -b --sourceMap false && rollup --config",
     "clean": "rm -rf lib dist tsconfig.tsbuildinfo",
     "watch": "tsc -b -w",
     "test": "pnpm build && vitest",
@@ -54,4 +54,4 @@
     "vite": "^6.1.0",
     "vite-plugin-top-level-await": "^1.4.4"
   }
-}
+}

packages/powersync-op-sqlite/src/db/OPSQLiteConnection.ts

@@ -10,6 +10,8 @@ import {
 
 export type OPSQLiteConnectionOptions = {
   baseDB: DB;
+  debugMode: boolean;
+  connectionName: string;
 };
 
 export type OPSQLiteUpdateNotification = {
@@ -35,6 +37,16 @@ export class OPSQLiteConnection extends BaseObserver<DBAdapterListener> {
     this.DB.updateHook((update) => {
       this.addTableUpdate(update);
     });
+
+    if (options.debugMode) {
+      const c = this.options.connectionName;
+      this.execute = withDebug(this.execute.bind(this), `[SQL execute ${c}]`);
+      this.executeRaw = withDebug(this.executeRaw.bind(this), `[SQL executeRaw ${c}]`);
+      this.executeBatch = withDebug(this.executeBatch.bind(this), `[SQL executeBatch ${c}]`);
+      this.get = withDebug(this.get.bind(this), `[SQL get ${c}]`);
+      this.getAll = withDebug(this.getAll.bind(this), `[SQL getAll ${c}]`);
+      this.getOptional = withDebug(this.getOptional.bind(this), `[SQL getOptional ${c}]`);
+    }
   }
 
   addTableUpdate(update: OPSQLiteUpdateNotification) {
@@ -133,3 +145,19 @@ export class OPSQLiteConnection extends BaseObserver<DBAdapterListener> {
     await this.get("PRAGMA table_info('sqlite_master')");
   }
 }
+
+function withDebug<T extends (sql: string, ...args: any[]) => Promise<any>>(fn: T, name: string): T {
+  return (async (sql: string, ...args: any[]): Promise<any> => {
+    const start = performance.now();
+    try {
+      const r = await fn(sql, ...args);
+      const duration = performance.now() - start;
+      console.log(name, `[${duration.toFixed(1)}ms]`, sql);
+      return r;
+    } catch (e: any) {
+      const duration = performance.now() - start;
+      console.error(name, `[ERROR: ${e.message}]`, `[${duration.toFixed(1)}ms]`, sql);
+      throw e;
+    }
+  }) as T;
+}

packages/powersync-op-sqlite/src/db/OPSqliteAdapter.ts

@@ -12,6 +12,7 @@ export type OPSQLiteAdapterOptions = {
   name: string;
   dbLocation?: string;
   sqliteOptions?: SqliteOptions;
+  debugMode?: boolean;
 };
 
 enum LockType {
@@ -50,7 +51,7 @@ export class OPSQLiteDBAdapter extends BaseObserver<DBAdapterListener> implement
       this.options.sqliteOptions!;
     const dbFilename = this.options.name;
 
-    this.writeConnection = await this.openConnection(dbFilename);
+    this.writeConnection = await this.openConnection('w');
 
     const baseStatements = [
       `PRAGMA busy_timeout = ${lockTimeoutMs}`,
@@ -89,16 +90,16 @@ export class OPSQLiteDBAdapter extends BaseObserver<DBAdapterListener> implement
 
     this.readConnections = [];
     for (let i = 0; i < READ_CONNECTIONS; i++) {
-      const conn = await this.openConnection(dbFilename);
+      const conn = await this.openConnection(`r-${i}`);
       for (let statement of readConnectionStatements) {
         await conn.execute(statement);
       }
       this.readConnections.push({ busy: false, connection: conn });
     }
   }
 
-  protected async openConnection(filenameOverride?: string): Promise<OPSQLiteConnection> {
-    const dbFilename = filenameOverride ?? this.options.name;
+  protected async openConnection(connectionName: string): Promise<OPSQLiteConnection> {
+    const dbFilename = this.options.name;
     const DB: DB = this.openDatabase(dbFilename, this.options.sqliteOptions?.encryptionKey ?? undefined);
 
     //Load extensions for all connections
@@ -108,7 +109,9 @@ export class OPSQLiteDBAdapter extends BaseObserver<DBAdapterListener> implement
     await DB.execute('SELECT powersync_init()');
 
     return new OPSQLiteConnection({
-      baseDB: DB
+      baseDB: DB,
+      debugMode: this.options.debugMode ?? false,
+      connectionName
     });
   }
 

packages/powersync-op-sqlite/src/db/OPSqliteDBOpenFactory.ts

@@ -19,7 +19,8 @@ export class OPSqliteOpenFactory implements SQLOpenFactory {
     return new OPSQLiteDBAdapter({
       name: this.options.dbFilename,
       dbLocation: this.options.dbLocation,
-      sqliteOptions: this.sqliteOptions
+      sqliteOptions: this.sqliteOptions,
+      debugMode: this.options.debugMode
     });
   }
 }

packages/web/src/db/adapters/LockedAsyncDatabaseAdapter.ts

@@ -67,10 +67,30 @@ export class LockedAsyncDatabaseAdapter
         const start = performance.now();
         try {
           const r = await originalExecute(sql, bindings);
+          const duration = performance.now() - start;
           performance.measure(`[SQL] ${sql}`, { start });
+          console.log(
+            '%c[SQL] %c%s %c%s',
+            'color: grey; font-weight: normal',
+            durationStyle(duration),
+            `[${duration.toFixed(1)}ms]`,
+            'color: grey; font-weight: normal',
+            sql
+          );
           return r;
         } catch (e: any) {
+          const duration = performance.now() - start;
           performance.measure(`[SQL] [ERROR: ${e.message}] ${sql}`, { start });
+          console.error(
+            '%c[SQL] %c%s %c%s %c%s',
+            'color: grey; font-weight: normal',
+            'color: red;  font-weight: normal',
+            `[ERROR: ${e.message}]`,
+            durationStyle(duration),
+            `[${duration.toFixed(1)}ms]`,
+            'color: grey; font-weight: normal',
+            sql
+          );
           throw e;
         }
       };
@@ -356,3 +376,13 @@ export class LockedAsyncDatabaseAdapter
     };
   };
 }
+
+function durationStyle(duration: number) {
+  if (duration < 30) {
+    return 'color: grey; font-weight: normal';
+  } else if (duration < 300) {
+    return 'color: blue; font-weight: normal';
+  } else {
+    return 'color: red; font-weight: normal';
+  }
+}