Merge branch 'master' into bump-deps

# Conflicts:
#	src/Model/index.js

CHANGELOG-Unreleased.md

@@ -8,6 +8,8 @@
 
 ### New features
 
+- Added `Database#experimentalIsVerbose` option
+
 ### Fixes
 
 - [ts] Improved LocalStorage type definition
@@ -17,6 +19,7 @@
 
 ### Changes
 
+- Improved Model diagnostic errors now always contain `table#id` of offending record
 - Update `better-sqlite3` to 9.x
 - [docs] Improved Android installation docs
 

package.json

@@ -1,7 +1,7 @@
 {
   "name": "@nozbe/watermelondb",
   "description": "Build powerful React Native and React web apps that scale from hundreds to tens of thousands of records and remain fast",
-  "version": "0.27.1",
+  "version": "0.28.0-0",
   "scripts": {
     "up": "yarn",
     "build": "NODE_ENV=production node ./scripts/make.mjs",

src/Database/index.d.ts

@@ -88,6 +88,11 @@ export default class Database {
   // Yes, this sucks and there should be some safety mechanisms or warnings. Please contribute!
   unsafeResetDatabase(): Promise<void>
 
+  // (experimental) if true, Models will print to console diagnostic information on every
+  // prepareCreate/Update/Delete call, as well as on commit (Database.batch() call). Note that this
+  // has a significant performance impact so should only be enabled when debugging.
+  experimentalIsVerbose: boolean
+
   _ensureInWriter(diagnosticMethodName: string): void
 
   // (experimental) puts Database in a broken state

src/Database/index.js

@@ -155,6 +155,25 @@ export default class Database {
 
     await this.adapter.batch(batchOperations)
 
+    // Debug info
+    if (this.experimentalIsVerbose) {
+      const debugInfo = batchOperations
+        .map(([type, table, rawOrId]) => {
+          switch (type) {
+            case 'create':
+            case 'update':
+              return `${type} ${table}#${(rawOrId: any).id}`
+            case 'markAsDeleted':
+            case 'destroyPermanently':
+              return `${type} ${table}#${(rawOrId: any)}`
+            default:
+              return `${type}???`
+          }
+        })
+        .join(', ')
+      logger.debug(`batch: ${debugInfo}`)
+    }
+
     // NOTE: We must make two passes to ensure all changes to caches are applied before subscribers are called
     const changes: [TableName<any>, CollectionChangeSet<any>][] = (Object.entries(
       changeNotifications,
@@ -361,10 +380,15 @@ export default class Database {
     }
   }
 
-  _ensureInWriter(diagnosticMethodName: string): void {
+  // (experimental) if true, Models will print to console diagnostic information on every
+  // prepareCreate/Update/Delete call, as well as on commit (Database.batch() call). Note that this
+  // has a significant performance impact so should only be enabled when debugging.
+  experimentalIsVerbose: boolean = false
+
+  _ensureInWriter(debugName: string): void {
     invariant(
       this._workQueue.isWriterRunning,
-      `${diagnosticMethodName} can only be called from inside of a Writer. See docs for more details.`,
+      `${debugName} can only be called from inside of a Writer. See docs for more details.`,
     )
   }
 

src/Database/test.js

@@ -1,6 +1,7 @@
 import { expectToRejectWithMessage } from '../__tests__/utils'
 import { mockDatabase } from '../__tests__/testModels'
 import { noop } from '../utils/fp'
+import { logger } from '../utils/common'
 import * as Q from '../QueryDescription'
 
 describe('Database', () => {
@@ -312,6 +313,39 @@ describe('Database', () => {
       const { database } = mockDatabase()
       await expectToRejectWithMessage(database.batch([], null), 'multiple arrays were passed')
     })
+    it(`prints debug information in verbose mode`, async () => {
+      const { database, tasks, projects } = mockDatabase()
+      const spy = jest.spyOn(logger, 'debug')
+
+      database.experimentalIsVerbose = true
+
+      await database.write(async () => {
+        const t1 = tasks.prepareCreate()
+        const t2 = tasks.prepareCreate()
+        const p1 = projects.prepareCreate()
+
+        await database.batch(t1, t2, p1)
+        expect(spy).toHaveBeenCalledWith(`prepareCreate: mock_tasks#${t1.id}`)
+        expect(spy).toHaveBeenCalledWith(`prepareCreate: mock_tasks#${t2.id}`)
+        expect(spy).toHaveBeenCalledWith(`prepareCreate: mock_projects#${p1.id}`)
+        expect(spy).toHaveBeenLastCalledWith(
+          `batch: create mock_tasks#${t1.id}, create mock_tasks#${t2.id}, create mock_projects#${p1.id}`,
+        )
+
+        t1.prepareUpdate()
+        t2.prepareMarkAsDeleted()
+        p1.prepareDestroyPermanently()
+
+        await database.batch(t1, t2, p1)
+
+        expect(spy).toHaveBeenCalledWith(`prepareUpdate: mock_tasks#${t1.id}`)
+        expect(spy).toHaveBeenCalledWith(`prepareMarkAsDeleted: mock_tasks#${t2.id}`)
+        expect(spy).toHaveBeenCalledWith(`prepareDestroyPermanently: mock_projects#${p1.id}`)
+        expect(spy).toHaveBeenLastCalledWith(
+          `batch: update mock_tasks#${t1.id}, markAsDeleted mock_tasks#${t2.id}, destroyPermanently mock_projects#${p1.id}`,
+        )
+      })
+    })
   })
 
   describe('Observation', () => {

src/Model/index.js

@@ -2,6 +2,7 @@
 
 import { type Observable, BehaviorSubject } from '../utils/rx'
 import { type Unsubscribe } from '../utils/subscriptions'
+import logger from '../utils/common/logger'
 import invariant from '../utils/common/invariant'
 import ensureSync from '../utils/common/ensureSync'
 import fromPairs from '../utils/fp/fromPairs'
@@ -107,7 +108,7 @@ export default class Model {
    * })
    */
   async update(recordUpdater: (this) => void = noop): Promise<this> {
-    this.db._ensureInWriter(`Model.update()`)
+    this.__ensureInWriter(`Model.update()`)
     const record = this.prepareUpdate(recordUpdater)
     await this.db.batch(this)
     return record
@@ -124,7 +125,7 @@ export default class Model {
   prepareUpdate(recordUpdater: (this) => void = noop): this {
     invariant(
       !this._preparedState,
-      `Cannot update a record with pending changes. Update attempted for table ${this.table} and record ${this.id}.`,
+      `Cannot update a record with pending changes (${this.__debugName})`,
     )
     this.__ensureNotDisposable(`Model.prepareUpdate()`)
     this._isEditing = true
@@ -152,10 +153,11 @@ export default class Model {
       process.nextTick(() => {
         invariant(
           this._preparedState !== 'update',
-          `record.prepareUpdate was called on ${this.table}#${this.id} but wasn't sent to batch() synchronously -- this is bad!`,
+          `record.prepareUpdate was called on ${this.__debugName} but wasn't sent to batch() synchronously -- this is bad!`,
         )
       })
     }
+    this.__logVerbose('prepareUpdate')
 
     return this
   }
@@ -166,7 +168,7 @@ export default class Model {
    * Note: This method must be called within a Writer {@link Database#write}.
    */
   async markAsDeleted(): Promise<void> {
-    this.db._ensureInWriter(`Model.markAsDeleted()`)
+    this.__ensureInWriter(`Model.markAsDeleted()`)
     this.__ensureNotDisposable(`Model.markAsDeleted()`)
     await this.db.batch(this.prepareMarkAsDeleted())
   }
@@ -180,10 +182,14 @@ export default class Model {
    * @see {Database#batch}
    */
   prepareMarkAsDeleted(): this {
-    invariant(!this._preparedState, `Cannot mark a record with pending changes as deleted`)
+    invariant(
+      !this._preparedState,
+      `Cannot mark a record with pending changes as deleted (${this.__debugName})`,
+    )
     this.__ensureNotDisposable(`Model.prepareMarkAsDeleted()`)
     this._raw._status = 'deleted'
     this._preparedState = 'markAsDeleted'
+    this.__logVerbose('prepareMarkAsDeleted')
     return this
   }
 
@@ -195,7 +201,7 @@ export default class Model {
    * Note: This method must be called within a Writer {@link Database#write}.
    */
   async destroyPermanently(): Promise<void> {
-    this.db._ensureInWriter(`Model.destroyPermanently()`)
+    this.__ensureInWriter(`Model.destroyPermanently()`)
     this.__ensureNotDisposable(`Model.destroyPermanently()`)
     await this.db.batch(this.prepareDestroyPermanently())
   }
@@ -211,10 +217,14 @@ export default class Model {
    * @see {Database#batch}
    */
   prepareDestroyPermanently(): this {
-    invariant(!this._preparedState, `Cannot destroy permanently a record with pending changes`)
+    invariant(
+      !this._preparedState,
+      `Cannot destroy permanently record with pending changes (${this.__debugName})`,
+    )
     this.__ensureNotDisposable(`Model.prepareDestroyPermanently()`)
     this._raw._status = 'deleted'
     this._preparedState = 'destroyPermanently'
+    this.__logVerbose('prepareDestroyPermanently')
     return this
   }
 
@@ -227,7 +237,7 @@ export default class Model {
    * Note: This method must be called within a Writer {@link Database#write}.
    */
   async experimentalMarkAsDeleted(): Promise<void> {
-    this.db._ensureInWriter(`Model.experimental_markAsDeleted()`)
+    this.__ensureInWriter(`Model.experimentalMarkAsDeleted()`)
     this.__ensureNotDisposable(`Model.experimentalMarkAsDeleted()`)
     const records = await fetchDescendants(this)
     records.forEach((model) => model.prepareMarkAsDeleted())
@@ -246,7 +256,7 @@ export default class Model {
    * Note: This method must be called within a Writer {@link Database#write}.
    */
   async experimentalDestroyPermanently(): Promise<void> {
-    this.db._ensureInWriter(`Model.experimental_destroyPermanently()`)
+    this.__ensureInWriter(`Model.experimentalDestroyPermanently()`)
     this.__ensureNotDisposable(`Model.experimentalDestroyPermanently()`)
     const records = await fetchDescendants(this)
     records.forEach((model) => model.prepareDestroyPermanently())
@@ -265,7 +275,10 @@ export default class Model {
    * Emits `complete` signal if this record is deleted (marked as deleted or permanently destroyed)
    */
   observe(): Observable<this> {
-    invariant(this._preparedState !== 'create', `Cannot observe uncommitted record`)
+    invariant(
+      this._preparedState !== 'create',
+      `Cannot observe uncommitted record (${this.__debugName})`,
+    )
     return this._getChanges()
   }
 
@@ -358,6 +371,8 @@ export default class Model {
     ensureSync(recordBuilder(record))
     record._isEditing = false
 
+    record.__logVerbose('prepareCreate')
+
     return record
   }
 
@@ -367,6 +382,7 @@ export default class Model {
   ): this {
     const record = new this(collection, sanitizedRaw(dirtyRaw, collection.schema))
     record._preparedState = 'create'
+    record.__logVerbose('prepareCreateFromDirtyRaw')
     return record
   }
 
@@ -376,6 +392,7 @@ export default class Model {
   ): this {
     const record = new this(collection, sanitizedRaw(dirtyRaw, collection.schema))
     record._raw._status = 'disposable'
+    record.__logVerbose('disposableFromDirtyRaw')
     return record
   }
 
@@ -435,20 +452,37 @@ export default class Model {
     setRawSanitized(this._raw, rawFieldName, rawValue, this.collection.schema.columns[rawFieldName])
   }
 
+  get __debugName(): string {
+    return `${this.table}#${this.id}`
+  }
+
   __ensureCanSetRaw(): void {
     this.__ensureNotDisposable(`Model._setRaw()`)
-    invariant(this._isEditing, 'Not allowed to change record outside of create/update()')
+    invariant(
+      this._isEditing,
+      `Not allowed to change record ${this.__debugName} outside of create/update()`,
+    )
     invariant(
       !(this._getChanges(): $FlowFixMe<BehaviorSubject<any>>).isStopped &&
         this._raw._status !== 'deleted',
-      'Not allowed to change deleted records',
+      `Not allowed to change deleted record ${this.__debugName}`,
     )
   }
 
   __ensureNotDisposable(debugName: string): void {
     invariant(
       this._raw._status !== 'disposable',
-      `${debugName} cannot be called on a disposable record`,
+      `${debugName} cannot be called on a disposable record ${this.__debugName}`,
     )
   }
+
+  __ensureInWriter(debugName: string): void {
+    this.db._ensureInWriter(`${debugName} (${this.__debugName})`)
+  }
+
+  __logVerbose(debugName: string): void {
+    if (this.db.experimentalIsVerbose) {
+      logger.debug(`${debugName}: ${this.__debugName}`)
+    }
+  }
 }

src/Model/test.js

@@ -384,7 +384,7 @@ describe('Safety features', () => {
         m1.update(() => {
           m1.name = 'new'
         }),
-        'Not allowed to change deleted records',
+        'Not allowed to change deleted record',
       )
     })
   })
@@ -399,7 +399,7 @@ describe('Safety features', () => {
         m1.update(() => {
           m1.name = 'new'
         }),
-        'Not allowed to change deleted records',
+        'Not allowed to change deleted record',
       )
     })
   })

src/utils/common/logger/index.d.ts

@@ -1,6 +1,8 @@
 declare class Logger {
   silent: boolean
 
+  debug(...messages: any[]): void
+
   log(...messages: any[]): void
 
   warn(...messages: any[]): void

src/utils/common/logger/index.js

@@ -9,6 +9,10 @@ const formatMessages = (messages: Array<any>) => {
 class Logger {
   silent: boolean = false
 
+  debug(...messages: any[]): void {
+    !this.silent && console.debug(...formatMessages(messages))
+  }
+
   log(...messages: any[]): void {
     !this.silent && console.log(...formatMessages(messages))
   }