From 3eda284d75dba381f3f1f8819d46d5b7a1775962 Mon Sep 17 00:00:00 2001 From: Cedrick Cooke Date: Wed, 4 Sep 2024 16:51:40 -0700 Subject: [PATCH 1/7] Initial logging framework, events for DB open/close --- core/src/jsMain/kotlin/Database.kt | 37 ++++++++++++++++--- .../kotlin/logs/EventAsMessageLogger.kt | 37 +++++++++++++++++++ .../src/jsMain/kotlin/logs/FilteringLogger.kt | 21 +++++++++++ core/src/jsMain/kotlin/logs/Logger.kt | 7 ++++ core/src/jsMain/kotlin/logs/NoOpLogger.kt | 8 ++++ core/src/jsMain/kotlin/logs/PrintLogger.kt | 14 +++++++ core/src/jsMain/kotlin/logs/Type.kt | 15 ++++++++ 7 files changed, 134 insertions(+), 5 deletions(-) create mode 100644 core/src/jsMain/kotlin/logs/EventAsMessageLogger.kt create mode 100644 core/src/jsMain/kotlin/logs/FilteringLogger.kt create mode 100644 core/src/jsMain/kotlin/logs/Logger.kt create mode 100644 core/src/jsMain/kotlin/logs/NoOpLogger.kt create mode 100644 core/src/jsMain/kotlin/logs/PrintLogger.kt create mode 100644 core/src/jsMain/kotlin/logs/Type.kt diff --git a/core/src/jsMain/kotlin/Database.kt b/core/src/jsMain/kotlin/Database.kt index 9ede687..0439ab6 100644 --- a/core/src/jsMain/kotlin/Database.kt +++ b/core/src/jsMain/kotlin/Database.kt @@ -4,9 +4,13 @@ import com.juul.indexeddb.external.IDBDatabase import com.juul.indexeddb.external.IDBFactory import com.juul.indexeddb.external.IDBVersionChangeEvent import com.juul.indexeddb.external.indexedDB +import com.juul.indexeddb.logs.Logger +import com.juul.indexeddb.logs.NoOpLogger +import com.juul.indexeddb.logs.Type import kotlinx.browser.window import kotlinx.coroutines.Dispatchers import kotlinx.coroutines.withContext +import org.w3c.dom.events.Event /** * Inside the [initialize] block, you must not call any `suspend` functions except for: @@ -17,6 +21,7 @@ import kotlinx.coroutines.withContext public suspend fun openDatabase( name: String, version: Int, + logger: Logger = NoOpLogger, initialize: suspend VersionChangeTransaction.( database: Database, oldVersion: Int, @@ -25,6 +30,7 @@ public suspend fun openDatabase( ): Database = withContext(Dispatchers.Unconfined) { val indexedDB: IDBFactory? = js("self.indexedDB || self.webkitIndexedDB") as? IDBFactory val factory = checkNotNull(indexedDB) { "Your browser doesn't support IndexedDB." } + logger.log(Type.DatabaseOpen) { "Opening database `$name` at version `$version`" } val request = factory.open(name, version) val versionChangeEvent = request.onNextEvent("success", "upgradeneeded", "error", "blocked") { event -> when (event.type) { @@ -34,12 +40,16 @@ public suspend fun openDatabase( else -> null } } - Database(request.result).also { database -> + Database(request.result, logger).also { database -> if (versionChangeEvent != null) { + logger.log(Type.DatabaseUpgrade, versionChangeEvent) { + "Upgrading database `$name` from version `${versionChangeEvent.oldVersion}` to `${versionChangeEvent.newVersion}`" + } val transaction = VersionChangeTransaction(checkNotNull(request.transaction)) transaction.initialize(database, versionChangeEvent.oldVersion, versionChangeEvent.newVersion) transaction.awaitCompletion() } + logger.log(Type.DatabaseOpen) { "Opened database `$name`" } } } @@ -56,14 +66,20 @@ public suspend fun deleteDatabase(name: String) { public class Database internal constructor( database: IDBDatabase, + private val logger: Logger, ) { + private val name = database.name private var database: IDBDatabase? = database init { + val callback = { event: Event -> + logger.log(Type.DatabaseClose, event) { "Closing database `$name` due to event" } + onClose() + } // listen for database structure changes (e.g., upgradeneeded while DB is open or deleteDatabase) - database.addEventListener("versionchange", { close() }) + database.addEventListener("versionchange", callback) // listen for force close, e.g., browser profile on a USB drive that's ejected or db deleted through dev tools - database.addEventListener("close", { close() }) + database.addEventListener("close", callback) } internal fun ensureDatabase(): IDBDatabase = checkNotNull(database) { "database is closed" } @@ -113,8 +129,19 @@ public class Database internal constructor( } public fun close() { - database?.close() - database = null + logger.log(Type.DatabaseClose) { "Closing database `$name` due to explicit `close()`" } + onClose() + } + + private fun onClose() { + val db = database + if (db != null) { + db.close() + database = null + logger.log(Type.DatabaseClose) { "Closed database `$name`" } + } else { + logger.log(Type.DatabaseClose) { "Close skipped, database `$name` already closed" } + } } } diff --git a/core/src/jsMain/kotlin/logs/EventAsMessageLogger.kt b/core/src/jsMain/kotlin/logs/EventAsMessageLogger.kt new file mode 100644 index 0000000..72a11a4 --- /dev/null +++ b/core/src/jsMain/kotlin/logs/EventAsMessageLogger.kt @@ -0,0 +1,37 @@ +package com.juul.indexeddb.logs + +import com.juul.indexeddb.external.IDBVersionChangeEvent +import org.w3c.dom.events.Event + +public fun Logger.embedEventsInMessages( + separator: String = "\n ", +): Logger = EventAsMessageLogger(separator, this) + +private class EventAsMessageLogger( + private val separator: String, + private val delegate: Logger, +) : Logger { + + override fun log(type: Type, event: Event?, message: () -> String) { + delegate.log(type, null) { + buildString { + append(message()) + if (event != null) { + for (line in propertyStrings(event)) { + append(separator) + append(line) + } + } + } + } + } + + private fun propertyStrings(event: Event): List = buildList { + add("type: ${event.type}") + add("target: ${event.target}") + if (event is IDBVersionChangeEvent) { + add("oldVersion: ${event.oldVersion}") + add("newVersion: ${event.newVersion}") + } + } +} diff --git a/core/src/jsMain/kotlin/logs/FilteringLogger.kt b/core/src/jsMain/kotlin/logs/FilteringLogger.kt new file mode 100644 index 0000000..fe9120d --- /dev/null +++ b/core/src/jsMain/kotlin/logs/FilteringLogger.kt @@ -0,0 +1,21 @@ +package com.juul.indexeddb.logs + +import org.w3c.dom.events.Event + +public fun Logger.filterTypes(vararg whitelist: Type): Logger = + filterTypes(whitelist.toSet()) + +public fun Logger.filterTypes(whitelist: Set): Logger = + FilteringLogger(whitelist, this) + +private class FilteringLogger( + val whitelist: Set, + val delegate: Logger, +) : Logger { + + override fun log(type: Type, event: Event?, message: () -> String) { + if (type in whitelist) { + delegate.log(type, event, message) + } + } +} diff --git a/core/src/jsMain/kotlin/logs/Logger.kt b/core/src/jsMain/kotlin/logs/Logger.kt new file mode 100644 index 0000000..54043dc --- /dev/null +++ b/core/src/jsMain/kotlin/logs/Logger.kt @@ -0,0 +1,7 @@ +package com.juul.indexeddb.logs + +import org.w3c.dom.events.Event + +public interface Logger { + public fun log(type: Type, event: Event? = null, message: () -> String) +} diff --git a/core/src/jsMain/kotlin/logs/NoOpLogger.kt b/core/src/jsMain/kotlin/logs/NoOpLogger.kt new file mode 100644 index 0000000..32da937 --- /dev/null +++ b/core/src/jsMain/kotlin/logs/NoOpLogger.kt @@ -0,0 +1,8 @@ +package com.juul.indexeddb.logs + +import org.w3c.dom.events.Event + +public object NoOpLogger : Logger { + + override fun log(type: Type, event: Event?, message: () -> String) {} +} diff --git a/core/src/jsMain/kotlin/logs/PrintLogger.kt b/core/src/jsMain/kotlin/logs/PrintLogger.kt new file mode 100644 index 0000000..e19c248 --- /dev/null +++ b/core/src/jsMain/kotlin/logs/PrintLogger.kt @@ -0,0 +1,14 @@ +package com.juul.indexeddb.logs + +import org.w3c.dom.events.Event + +public object PrintLogger : Logger { + + override fun log(type: Type, event: Event?, message: () -> String) { + val msg = message() + when (event) { + null -> println("$type: $msg") + else -> println("$type (event=$event): $msg") + } + } +} diff --git a/core/src/jsMain/kotlin/logs/Type.kt b/core/src/jsMain/kotlin/logs/Type.kt new file mode 100644 index 0000000..7fd9cb8 --- /dev/null +++ b/core/src/jsMain/kotlin/logs/Type.kt @@ -0,0 +1,15 @@ +package com.juul.indexeddb.logs + +public enum class Type { + CursorClose, + CursorOpen, + CursorValue, + DatabaseClose, + DatabaseDelete, + DatabaseOpen, + DatabaseUpgrade, + QueryGet, + QuerySet, + TransactionClose, + TransactionOpen, +} From f12c9acd21328c97fcae405fe3472ddd990656f6 Mon Sep 17 00:00:00 2001 From: Cedrick Cooke Date: Wed, 4 Sep 2024 18:15:14 -0700 Subject: [PATCH 2/7] Per-query logging, sans cursor --- core/src/jsMain/kotlin/Database.kt | 53 +++++-- core/src/jsMain/kotlin/Index.kt | 7 + core/src/jsMain/kotlin/ObjectStore.kt | 7 + core/src/jsMain/kotlin/Queryable.kt | 2 + core/src/jsMain/kotlin/Transaction.kt | 145 ++++++++---------- .../kotlin/logs/EventAsMessageLogger.kt | 8 +- core/src/jsMain/kotlin/logs/PrintLogger.kt | 2 +- core/src/jsMain/kotlin/logs/Type.kt | 15 +- 8 files changed, 124 insertions(+), 115 deletions(-) diff --git a/core/src/jsMain/kotlin/Database.kt b/core/src/jsMain/kotlin/Database.kt index 0439ab6..4379221 100644 --- a/core/src/jsMain/kotlin/Database.kt +++ b/core/src/jsMain/kotlin/Database.kt @@ -30,7 +30,7 @@ public suspend fun openDatabase( ): Database = withContext(Dispatchers.Unconfined) { val indexedDB: IDBFactory? = js("self.indexedDB || self.webkitIndexedDB") as? IDBFactory val factory = checkNotNull(indexedDB) { "Your browser doesn't support IndexedDB." } - logger.log(Type.DatabaseOpen) { "Opening database `$name` at version `$version`" } + logger.log(Type.Database) { "Opening database `$name` at version `$version`" } val request = factory.open(name, version) val versionChangeEvent = request.onNextEvent("success", "upgradeneeded", "error", "blocked") { event -> when (event.type) { @@ -42,21 +42,29 @@ public suspend fun openDatabase( } Database(request.result, logger).also { database -> if (versionChangeEvent != null) { - logger.log(Type.DatabaseUpgrade, versionChangeEvent) { + logger.log(Type.Database, versionChangeEvent) { "Upgrading database `$name` from version `${versionChangeEvent.oldVersion}` to `${versionChangeEvent.newVersion}`" } - val transaction = VersionChangeTransaction(checkNotNull(request.transaction)) + logger.log(Type.Transaction) { "Opened `versionchange` transaction with id `0`" } + val transaction = VersionChangeTransaction(checkNotNull(request.transaction), logger, transactionId = 0) transaction.initialize(database, versionChangeEvent.oldVersion, versionChangeEvent.newVersion) - transaction.awaitCompletion() + transaction.awaitCompletion { event -> + logger.log(Type.Transaction, event) { "Closed `versionchange` transaction with id `0`" } + } } - logger.log(Type.DatabaseOpen) { "Opened database `$name`" } + logger.log(Type.Database) { "Opened database `$name`" } } } -public suspend fun deleteDatabase(name: String) { +public suspend fun deleteDatabase( + name: String, + logger: Logger = NoOpLogger, +) { + logger.log(Type.Database) { "Deleting database `$name`" } val factory = checkNotNull(window.indexedDB) { "Your browser doesn't support IndexedDB." } val request = factory.deleteDatabase(name) request.onNextEvent("success", "error", "blocked") { event -> + logger.log(Type.Database, event) { "Deleted database `$name`" } when (event.type) { "error", "blocked" -> throw ErrorEventException(event) else -> null @@ -70,11 +78,12 @@ public class Database internal constructor( ) { private val name = database.name private var database: IDBDatabase? = database + private var transactionId = 1L init { val callback = { event: Event -> - logger.log(Type.DatabaseClose, event) { "Closing database `$name` due to event" } - onClose() + logger.log(Type.Database, event) { "Closing database `$name` due to event" } + tryClose() } // listen for database structure changes (e.g., upgradeneeded while DB is open or deleteDatabase) database.addEventListener("versionchange", callback) @@ -95,11 +104,18 @@ public class Database internal constructor( durability: Durability = Durability.Default, action: suspend Transaction.() -> T, ): T = withContext(Dispatchers.Unconfined) { + val id = transactionId++ val transaction = Transaction( ensureDatabase().transaction(arrayOf(*store), "readonly", transactionOptions(durability)), + logger, + id, ) + + logger.log(Type.Transaction) { "Opened `readonly` transaction with id `$id` using stores ${store.joinToString { "`$it`" }}" } val result = transaction.action() - transaction.awaitCompletion() + transaction.awaitCompletion { event -> + logger.log(Type.Transaction, event) { "Closed `readonly` transaction with id `$id`" } + } result } @@ -114,8 +130,11 @@ public class Database internal constructor( durability: Durability = Durability.Default, action: suspend WriteTransaction.() -> T, ): T = withContext(Dispatchers.Unconfined) { + val id = transactionId++ val transaction = WriteTransaction( ensureDatabase().transaction(arrayOf(*store), "readwrite", transactionOptions(durability)), + logger, + id, ) with(transaction) { // Force overlapping transactions to not call `action` until prior transactions complete. @@ -123,24 +142,28 @@ public class Database internal constructor( .openKeyCursor(autoContinue = false) .collect { it.close() } } + + logger.log(Type.Transaction) { "Opened `readwrite` transaction with id `$id`" } val result = transaction.action() - transaction.awaitCompletion() + transaction.awaitCompletion { event -> + logger.log(Type.Transaction, event) { "Closed `readwrite` transaction with id `$id`" } + } result } public fun close() { - logger.log(Type.DatabaseClose) { "Closing database `$name` due to explicit `close()`" } - onClose() + logger.log(Type.Database) { "Closing database `$name` due to explicit `close()`" } + tryClose() } - private fun onClose() { + private fun tryClose() { val db = database if (db != null) { db.close() database = null - logger.log(Type.DatabaseClose) { "Closed database `$name`" } + logger.log(Type.Database) { "Closed database `$name`" } } else { - logger.log(Type.DatabaseClose) { "Close skipped, database `$name` already closed" } + logger.log(Type.Database) { "Close skipped, database `$name` already closed" } } } } diff --git a/core/src/jsMain/kotlin/Index.kt b/core/src/jsMain/kotlin/Index.kt index 3579cd1..039c2b3 100644 --- a/core/src/jsMain/kotlin/Index.kt +++ b/core/src/jsMain/kotlin/Index.kt @@ -7,6 +7,13 @@ import com.juul.indexeddb.external.IDBIndex public class Index internal constructor( internal val index: IDBIndex, ) : Queryable() { + + override val type: String + get() = "index" + + override val name: String + get() = index.name + override fun requestGet(key: Key): Request = Request(index.get(key.toJs())) diff --git a/core/src/jsMain/kotlin/ObjectStore.kt b/core/src/jsMain/kotlin/ObjectStore.kt index 0fb5aa3..d1e5e6e 100644 --- a/core/src/jsMain/kotlin/ObjectStore.kt +++ b/core/src/jsMain/kotlin/ObjectStore.kt @@ -7,6 +7,13 @@ import com.juul.indexeddb.external.IDBObjectStore public class ObjectStore internal constructor( internal val objectStore: IDBObjectStore, ) : Queryable() { + + override val type: String + get() = "object store" + + override val name: String + get() = objectStore.name + override fun requestGet(key: Key): Request = Request(objectStore.get(key.toJs())) diff --git a/core/src/jsMain/kotlin/Queryable.kt b/core/src/jsMain/kotlin/Queryable.kt index 5130bb1..f9d1688 100644 --- a/core/src/jsMain/kotlin/Queryable.kt +++ b/core/src/jsMain/kotlin/Queryable.kt @@ -4,6 +4,8 @@ import com.juul.indexeddb.external.IDBCursor import com.juul.indexeddb.external.IDBCursorWithValue public sealed class Queryable { + internal abstract val type: String + internal abstract val name: String internal abstract fun requestGet(key: Key): Request internal abstract fun requestGetAll(query: Key?): Request> internal abstract fun requestOpenCursor(query: Key?, direction: Cursor.Direction): Request diff --git a/core/src/jsMain/kotlin/Transaction.kt b/core/src/jsMain/kotlin/Transaction.kt index 8aee08a..e0a4be2 100644 --- a/core/src/jsMain/kotlin/Transaction.kt +++ b/core/src/jsMain/kotlin/Transaction.kt @@ -3,6 +3,8 @@ package com.juul.indexeddb import com.juul.indexeddb.external.IDBCursor import com.juul.indexeddb.external.IDBRequest import com.juul.indexeddb.external.IDBTransaction +import com.juul.indexeddb.logs.Logger +import com.juul.indexeddb.logs.Type import kotlinx.coroutines.channels.SendChannel import kotlinx.coroutines.channels.awaitClose import kotlinx.coroutines.flow.Flow @@ -11,10 +13,14 @@ import org.w3c.dom.events.Event public open class Transaction internal constructor( internal val transaction: IDBTransaction, + internal val logger: Logger, + internal val transactionId: Long, ) { + internal var operationId: Int = 0 - internal suspend fun awaitCompletion() { + internal suspend fun awaitCompletion(onComplete: ((Event) -> Unit)? = null) { transaction.onNextEvent("complete", "abort", "error") { event -> + onComplete?.invoke(event) when (event.type) { "abort" -> throw AbortTransactionException(event) "error" -> throw ErrorEventException(event) @@ -23,22 +29,17 @@ public open class Transaction internal constructor( } } - public fun objectStore(name: String): ObjectStore = - ObjectStore(transaction.objectStore(name)) - - public suspend fun Queryable.get(key: Key): dynamic { - val request = requestGet(key).request + internal suspend inline fun Queryable.request( + functionName: String, + crossinline makeRequest: () -> IDBRequest, + ): T { + val id = operationId++ + logger.log(Type.Query) { "$functionName request on $type `$name` (transaction $transactionId, request $id)" } + val request = makeRequest() return request.onNextEvent("success", "error") { event -> - when (event.type) { - "error" -> throw ErrorEventException(event) - else -> request.result + logger.log(Type.Query, event) { + "$functionName response on $type `$name` (transaction $transactionId, request $id)" } - } - } - - public suspend fun Queryable.getAll(query: Key? = null): Array { - val request = requestGetAll(query).request - return request.onNextEvent("success", "error") { event -> when (event.type) { "error" -> throw ErrorEventException(event) else -> request.result @@ -46,6 +47,15 @@ public open class Transaction internal constructor( } } + public fun objectStore(name: String): ObjectStore = + ObjectStore(transaction.objectStore(name)) + + public suspend fun Queryable.get(key: Key): dynamic = + request("get") { requestGet(key).request } + + public suspend fun Queryable.getAll(query: Key? = null): Array = + request("getAll") { requestGetAll(query).request } + @Deprecated( "In the future, `autoContinue` will be a required parameter.", ReplaceWith("openCursor(query, direction, cursorStart, autoContinue = true)"), @@ -158,15 +168,8 @@ public open class Transaction internal constructor( } } - public suspend fun Queryable.count(query: Key? = null): Int { - val request = requestCount(query).request - return request.onNextEvent("success", "error") { event -> - when (event.type) { - "error" -> throw ErrorEventException(event) - else -> request.result - } - } - } + public suspend fun Queryable.count(query: Key? = null): Int = + request("count") { requestCount(query).request } public fun ObjectStore.index(name: String): Index = Index(objectStore.index(name)) @@ -174,7 +177,9 @@ public open class Transaction internal constructor( public open class WriteTransaction internal constructor( transaction: IDBTransaction, -) : Transaction(transaction) { + logger: Logger, + transactionId: Long, +) : Transaction(transaction, logger, transactionId) { /** * Adds a new item to the database using an in-line or auto-incrementing key. If an item with the same @@ -185,15 +190,8 @@ public open class WriteTransaction internal constructor( * Generally, you'll want to create an explicit `external interface` and pass that in, to guarantee that Kotlin * doesn't mangle, prefix, or otherwise mess with your field names. */ - public suspend fun ObjectStore.add(item: dynamic): dynamic { - val request = objectStore.add(item) - return request.onNextEvent("success", "error") { event -> - when (event.type) { - "error" -> throw ErrorEventException(event) - else -> request.result - } - } - } + public suspend fun ObjectStore.add(item: dynamic): dynamic = + request("add") { objectStore.add(item) } /** * Adds a new item to the database using an explicit out-of-line key. If an item with the same key already @@ -204,15 +202,8 @@ public open class WriteTransaction internal constructor( * Generally, you'll want to create an explicit `external interface` and pass that in, to guarantee that Kotlin * doesn't mangle, prefix, or otherwise mess with your field names. */ - public suspend fun ObjectStore.add(item: dynamic, key: Key): dynamic { - val request = objectStore.add(item, key.toJs()) - return request.onNextEvent("success", "error") { event -> - when (event.type) { - "error" -> throw ErrorEventException(event) - else -> request.result - } - } - } + public suspend fun ObjectStore.add(item: dynamic, key: Key): dynamic = + request("add") { objectStore.add(item, key.toJs()) } /** * Adds an item to or updates an item in the database using an in-line or auto-incrementing key. If an item @@ -224,15 +215,8 @@ public open class WriteTransaction internal constructor( * Generally, you'll want to create an explicit `external interface` and pass that in, to guarantee that Kotlin * doesn't mangle, prefix, or otherwise mess with your field names. */ - public suspend fun ObjectStore.put(item: dynamic): dynamic { - val request = objectStore.put(item) - return request.onNextEvent("success", "error") { event -> - when (event.type) { - "error" -> throw ErrorEventException(event) - else -> request.result - } - } - } + public suspend fun ObjectStore.put(item: dynamic): dynamic = + request("put") { objectStore.put(item) } /** * Adds an item to or updates an item in the database using an explicit out-of-line key. If an item with the @@ -243,34 +227,15 @@ public open class WriteTransaction internal constructor( * Generally, you'll want to create an explicit `external interface` and pass that in, to guarantee that Kotlin * doesn't mangle, prefix, or otherwise mess with your field names. */ - public suspend fun ObjectStore.put(item: dynamic, key: Key): dynamic { - val request = objectStore.put(item, key.toJs()) - return request.onNextEvent("success", "error") { event -> - when (event.type) { - "error" -> throw ErrorEventException(event) - else -> request.result - } - } - } + public suspend fun ObjectStore.put(item: dynamic, key: Key): dynamic = + request("put") { objectStore.put(item, key.toJs()) } public suspend fun ObjectStore.delete(key: Key) { - val request = objectStore.delete(key.toJs()) - request.onNextEvent("success", "error") { event -> - when (event.type) { - "error" -> throw ErrorEventException(event) - else -> Unit - } - } + request("delete") { objectStore.delete(key.toJs()) } } public suspend fun ObjectStore.clear() { - val request = objectStore.clear() - request.onNextEvent("success", "error") { event -> - when (event.type) { - "error" -> throw ErrorEventException(event) - else -> Unit - } - } + request("clear") { objectStore.clear() } } public suspend fun CursorWithValue.delete() { @@ -296,28 +261,40 @@ public open class WriteTransaction internal constructor( public class VersionChangeTransaction internal constructor( transaction: IDBTransaction, -) : WriteTransaction(transaction) { + logger: Logger, + transactionId: Long, +) : WriteTransaction(transaction, logger, transactionId) { /** Creates an object-store that uses explicit out-of-line keys. */ - public fun Database.createObjectStore(name: String): ObjectStore = - ObjectStore(ensureDatabase().createObjectStore(name)) + public fun Database.createObjectStore(name: String): ObjectStore { + logger.log(Type.Database) { "Creating object store: $name" } + return ObjectStore(ensureDatabase().createObjectStore(name)) + } /** Creates an object-store that uses in-line keys. */ - public fun Database.createObjectStore(name: String, keyPath: KeyPath): ObjectStore = - ObjectStore(ensureDatabase().createObjectStore(name, keyPath.toWrappedJs())) + public fun Database.createObjectStore(name: String, keyPath: KeyPath): ObjectStore { + logger.log(Type.Database) { "Creating object store: $name" } + return ObjectStore(ensureDatabase().createObjectStore(name, keyPath.toWrappedJs())) + } /** Creates an object-store that uses out-of-line keys with a key-generator. */ - public fun Database.createObjectStore(name: String, autoIncrement: AutoIncrement): ObjectStore = - ObjectStore(ensureDatabase().createObjectStore(name, autoIncrement.toJs())) + public fun Database.createObjectStore(name: String, autoIncrement: AutoIncrement): ObjectStore { + logger.log(Type.Database) { "Creating object store: $name" } + return ObjectStore(ensureDatabase().createObjectStore(name, autoIncrement.toJs())) + } public fun Database.deleteObjectStore(name: String) { + logger.log(Type.Database) { "Deleting object store: $name" } ensureDatabase().deleteObjectStore(name) } - public fun ObjectStore.createIndex(name: String, keyPath: KeyPath, unique: Boolean): Index = - Index(objectStore.createIndex(name, keyPath.toUnwrappedJs(), jso { this.unique = unique })) + public fun ObjectStore.createIndex(name: String, keyPath: KeyPath, unique: Boolean): Index { + logger.log(Type.Database) { "Creating index: $name" } + return Index(objectStore.createIndex(name, keyPath.toUnwrappedJs(), jso { this.unique = unique })) + } public fun ObjectStore.deleteIndex(name: String) { + logger.log(Type.Database) { "Deleting index: $name" } objectStore.deleteIndex(name) } } diff --git a/core/src/jsMain/kotlin/logs/EventAsMessageLogger.kt b/core/src/jsMain/kotlin/logs/EventAsMessageLogger.kt index 72a11a4..e0c0242 100644 --- a/core/src/jsMain/kotlin/logs/EventAsMessageLogger.kt +++ b/core/src/jsMain/kotlin/logs/EventAsMessageLogger.kt @@ -27,11 +27,11 @@ private class EventAsMessageLogger( } private fun propertyStrings(event: Event): List = buildList { - add("type: ${event.type}") - add("target: ${event.target}") + // event.target explicitly excluded since it just prints stuff like [object IDBTransaction], not actually useful + add("event.type: ${event.type}") if (event is IDBVersionChangeEvent) { - add("oldVersion: ${event.oldVersion}") - add("newVersion: ${event.newVersion}") + add("event.oldVersion: ${event.oldVersion}") + add("event.newVersion: ${event.newVersion}") } } } diff --git a/core/src/jsMain/kotlin/logs/PrintLogger.kt b/core/src/jsMain/kotlin/logs/PrintLogger.kt index e19c248..79b3c69 100644 --- a/core/src/jsMain/kotlin/logs/PrintLogger.kt +++ b/core/src/jsMain/kotlin/logs/PrintLogger.kt @@ -8,7 +8,7 @@ public object PrintLogger : Logger { val msg = message() when (event) { null -> println("$type: $msg") - else -> println("$type (event=$event): $msg") + else -> println("$type (event=${event.type}): $msg") } } } diff --git a/core/src/jsMain/kotlin/logs/Type.kt b/core/src/jsMain/kotlin/logs/Type.kt index 7fd9cb8..cd4cd57 100644 --- a/core/src/jsMain/kotlin/logs/Type.kt +++ b/core/src/jsMain/kotlin/logs/Type.kt @@ -1,15 +1,8 @@ package com.juul.indexeddb.logs public enum class Type { - CursorClose, - CursorOpen, - CursorValue, - DatabaseClose, - DatabaseDelete, - DatabaseOpen, - DatabaseUpgrade, - QueryGet, - QuerySet, - TransactionClose, - TransactionOpen, + Database, + Transaction, + Query, + // TODO: Cursor events would be nice, but they're slightly more complicated } From e1b41bc6d8195158d4915b4322d33e0c7783b115 Mon Sep 17 00:00:00 2001 From: Cedrick Cooke Date: Wed, 4 Sep 2024 18:56:10 -0700 Subject: [PATCH 3/7] Logging improvements --- core/src/jsMain/kotlin/Database.kt | 30 ++++++++++--------- core/src/jsMain/kotlin/Transaction.kt | 43 +++++++++++++++++++++++++-- core/src/jsMain/kotlin/logs/Type.kt | 2 +- 3 files changed, 57 insertions(+), 18 deletions(-) diff --git a/core/src/jsMain/kotlin/Database.kt b/core/src/jsMain/kotlin/Database.kt index 4379221..510d616 100644 --- a/core/src/jsMain/kotlin/Database.kt +++ b/core/src/jsMain/kotlin/Database.kt @@ -45,11 +45,12 @@ public suspend fun openDatabase( logger.log(Type.Database, versionChangeEvent) { "Upgrading database `$name` from version `${versionChangeEvent.oldVersion}` to `${versionChangeEvent.newVersion}`" } - logger.log(Type.Transaction) { "Opened `versionchange` transaction with id `0`" } - val transaction = VersionChangeTransaction(checkNotNull(request.transaction), logger, transactionId = 0) + val id = database.transactionId++ + logger.log(Type.Transaction) { "Opened versionchange transaction $id" } + val transaction = VersionChangeTransaction(checkNotNull(request.transaction), logger, id) transaction.initialize(database, versionChangeEvent.oldVersion, versionChangeEvent.newVersion) transaction.awaitCompletion { event -> - logger.log(Type.Transaction, event) { "Closed `versionchange` transaction with id `0`" } + logger.log(Type.Transaction, event) { "Closed versionchange transaction $id" } } } logger.log(Type.Database) { "Opened database `$name`" } @@ -64,10 +65,13 @@ public suspend fun deleteDatabase( val factory = checkNotNull(window.indexedDB) { "Your browser doesn't support IndexedDB." } val request = factory.deleteDatabase(name) request.onNextEvent("success", "error", "blocked") { event -> - logger.log(Type.Database, event) { "Deleted database `$name`" } when (event.type) { - "error", "blocked" -> throw ErrorEventException(event) - else -> null + "error", "blocked" -> { + logger.log(Type.Database, event) { "Delete failed for database `$name`" } + throw ErrorEventException(event) + } + + else -> logger.log(Type.Database, event) { "Deleted database `$name`" } } } } @@ -78,7 +82,7 @@ public class Database internal constructor( ) { private val name = database.name private var database: IDBDatabase? = database - private var transactionId = 1L + internal var transactionId = 0L init { val callback = { event: Event -> @@ -111,10 +115,10 @@ public class Database internal constructor( id, ) - logger.log(Type.Transaction) { "Opened `readonly` transaction with id `$id` using stores ${store.joinToString { "`$it`" }}" } + logger.log(Type.Transaction) { "Opened readonly transaction $id using stores ${store.joinToString { "`$it`" }}" } val result = transaction.action() transaction.awaitCompletion { event -> - logger.log(Type.Transaction, event) { "Closed `readonly` transaction with id `$id`" } + logger.log(Type.Transaction, event) { "Closed readonly transaction $id" } } result } @@ -138,15 +142,13 @@ public class Database internal constructor( ) with(transaction) { // Force overlapping transactions to not call `action` until prior transactions complete. - objectStore(store.first()) - .openKeyCursor(autoContinue = false) - .collect { it.close() } + objectStore(store.first()).awaitTransaction() } - logger.log(Type.Transaction) { "Opened `readwrite` transaction with id `$id`" } + logger.log(Type.Transaction) { "Opened readwrite transaction $id" } val result = transaction.action() transaction.awaitCompletion { event -> - logger.log(Type.Transaction, event) { "Closed `readwrite` transaction with id `$id`" } + logger.log(Type.Transaction, event) { "Closed readwrite transaction $id" } } result } diff --git a/core/src/jsMain/kotlin/Transaction.kt b/core/src/jsMain/kotlin/Transaction.kt index e0a4be2..1b1c391 100644 --- a/core/src/jsMain/kotlin/Transaction.kt +++ b/core/src/jsMain/kotlin/Transaction.kt @@ -4,11 +4,13 @@ import com.juul.indexeddb.external.IDBCursor import com.juul.indexeddb.external.IDBRequest import com.juul.indexeddb.external.IDBTransaction import com.juul.indexeddb.logs.Logger +import com.juul.indexeddb.logs.NoOpLogger import com.juul.indexeddb.logs.Type import kotlinx.coroutines.channels.SendChannel import kotlinx.coroutines.channels.awaitClose import kotlinx.coroutines.flow.Flow import kotlinx.coroutines.flow.callbackFlow +import kotlinx.coroutines.flow.collect import org.w3c.dom.events.Event public open class Transaction internal constructor( @@ -34,11 +36,11 @@ public open class Transaction internal constructor( crossinline makeRequest: () -> IDBRequest, ): T { val id = operationId++ - logger.log(Type.Query) { "$functionName request on $type `$name` (transaction $transactionId, request $id)" } + logger.log(Type.Query) { "$functionName request on $type `$name` (transaction $transactionId, operation $id)" } val request = makeRequest() return request.onNextEvent("success", "error") { event -> logger.log(Type.Query, event) { - "$functionName response on $type `$name` (transaction $transactionId, request $id)" + "$functionName response on $type `$name` (transaction $transactionId, operation $id)" } when (event.type) { "error" -> throw ErrorEventException(event) @@ -86,12 +88,14 @@ public open class Transaction internal constructor( cursorStart: CursorStart? = null, autoContinue: Boolean, ): Flow = openCursorImpl( + "openCursor", query, direction, cursorStart, open = this::requestOpenCursor, wrap = ::CursorWithValue, autoContinue, + logger, ) @Deprecated( @@ -124,22 +128,51 @@ public open class Transaction internal constructor( cursorStart: CursorStart? = null, autoContinue: Boolean, ): Flow = openCursorImpl( + "openKeyCursor", query, direction, cursorStart, open = this::requestOpenKeyCursor, wrap = ::Cursor, autoContinue, + logger, ) - private suspend fun openCursorImpl( + /** + * Opens a key cursor, then immediately close it. This has the effect of being the minimally expensive query that + * still waits for the transaction to be available. + */ + internal suspend fun Queryable.awaitTransaction() { + openCursorImpl( + "openKeyCursor", + query = null, + direction = Cursor.Direction.Next, + cursorStart = null, + open = this::requestOpenKeyCursor, + wrap = ::Cursor, + autoContinue = false, + logger = NoOpLogger, + ).collect { + it.close() + } + // Since this function is an internal implementation detail, undo incrementing the operation id to avoid + // confusion where request 0 went. + operationId -= 1 + } + + private fun Queryable.openCursorImpl( + functionName: String, query: Key?, direction: Cursor.Direction, cursorStart: CursorStart?, open: (Key?, Cursor.Direction) -> Request, wrap: (U, SendChannel<*>) -> T, autoContinue: Boolean, + logger: Logger, ): Flow = callbackFlow { + val id = operationId++ + logger.log(Type.Cursor) { "$functionName request on $type `$name` (transaction $transactionId, operation $id)" } + var cursorStartAction = cursorStart val request = open(query, direction).request val onSuccess: (Event) -> Unit = { event -> @@ -149,6 +182,9 @@ public open class Transaction internal constructor( cursorStartAction?.apply(cursor) cursorStartAction = null } else if (cursor != null) { + logger.log(Type.Cursor, event) { + "Cursor value on $type `$name` (transaction $transactionId, operation $id)" + } val result = trySend(wrap(cursor, channel)) when { result.isSuccess -> if (autoContinue) cursor.`continue`() @@ -163,6 +199,7 @@ public open class Transaction internal constructor( request.addEventListener("success", onSuccess) request.addEventListener("error", onError) awaitClose { + logger.log(Type.Cursor) { "Cursor closed on $type `$name` (transaction $transactionId, operation $id)" } request.removeEventListener("success", onSuccess) request.removeEventListener("error", onError) } diff --git a/core/src/jsMain/kotlin/logs/Type.kt b/core/src/jsMain/kotlin/logs/Type.kt index cd4cd57..78ffe13 100644 --- a/core/src/jsMain/kotlin/logs/Type.kt +++ b/core/src/jsMain/kotlin/logs/Type.kt @@ -4,5 +4,5 @@ public enum class Type { Database, Transaction, Query, - // TODO: Cursor events would be nice, but they're slightly more complicated + Cursor, } From a1b189b683d511352213377092853ce2730a19dc Mon Sep 17 00:00:00 2001 From: Cedrick Cooke Date: Wed, 4 Sep 2024 19:12:11 -0700 Subject: [PATCH 4/7] Add khronicle logger --- gradle/libs.versions.toml | 1 + logging-khronicle/build.gradle.kts | 24 ++++++++++++++++++ logging-khronicle/src/jsMain/kotlin/Event.kt | 6 +++++ .../src/jsMain/kotlin/KhronicleLogger.kt | 25 +++++++++++++++++++ settings.gradle.kts | 1 + 5 files changed, 57 insertions(+) create mode 100644 logging-khronicle/build.gradle.kts create mode 100644 logging-khronicle/src/jsMain/kotlin/Event.kt create mode 100644 logging-khronicle/src/jsMain/kotlin/KhronicleLogger.kt diff --git a/gradle/libs.versions.toml b/gradle/libs.versions.toml index 8c909b1..eba4c6a 100644 --- a/gradle/libs.versions.toml +++ b/gradle/libs.versions.toml @@ -4,6 +4,7 @@ kotlin = "2.0.20" [libraries] coroutines-core = { module = "org.jetbrains.kotlinx:kotlinx-coroutines-core", version.ref = "coroutines" } +khronicle-core = { module = "com.juul.khronicle:khronicle-core", version = "0.3.0" } [plugins] dokka = { id = "org.jetbrains.dokka", version = "1.9.20" } diff --git a/logging-khronicle/build.gradle.kts b/logging-khronicle/build.gradle.kts new file mode 100644 index 0000000..9dfb22e --- /dev/null +++ b/logging-khronicle/build.gradle.kts @@ -0,0 +1,24 @@ +plugins { + kotlin("multiplatform") + id("org.jmailen.kotlinter") + id("org.jetbrains.dokka") + id("com.vanniktech.maven.publish") +} + +kotlin { + explicitApi() + + js { + browser() + binaries.library() + } + + sourceSets { + val commonMain by getting { + dependencies { + api(project(":core")) + api(libs.khronicle.core) + } + } + } +} diff --git a/logging-khronicle/src/jsMain/kotlin/Event.kt b/logging-khronicle/src/jsMain/kotlin/Event.kt new file mode 100644 index 0000000..8702818 --- /dev/null +++ b/logging-khronicle/src/jsMain/kotlin/Event.kt @@ -0,0 +1,6 @@ +package com.juul.indexeddb.logs + +import com.juul.khronicle.Key +import org.w3c.dom.events.Event + +public object Event : Key diff --git a/logging-khronicle/src/jsMain/kotlin/KhronicleLogger.kt b/logging-khronicle/src/jsMain/kotlin/KhronicleLogger.kt new file mode 100644 index 0000000..c2046c6 --- /dev/null +++ b/logging-khronicle/src/jsMain/kotlin/KhronicleLogger.kt @@ -0,0 +1,25 @@ +package com.juul.indexeddb.logs + +import com.juul.khronicle.Log +import com.juul.khronicle.LogLevel +import org.w3c.dom.events.Event as JsEvent + +public object KhronicleLogger : Logger { + + override fun log(type: Type, event: JsEvent?, message: () -> String) { + val level = when (event?.type) { + "error", "blocked" -> LogLevel.Error + else -> when (type) { + Type.Database -> LogLevel.Info + Type.Transaction -> LogLevel.Debug + else -> LogLevel.Verbose + } + } + Log.dynamic(level = level, tag = "IndexedDB/$type") { metadata -> + if (event != null) { + metadata[Event] = event + } + message() + } + } +} diff --git a/settings.gradle.kts b/settings.gradle.kts index 339019b..eccfbb7 100644 --- a/settings.gradle.kts +++ b/settings.gradle.kts @@ -11,4 +11,5 @@ pluginManagement { include( "core", "external", + "logging-khronicle", ) From 58f36afd78005325b0f738cac263e6ef8f720509 Mon Sep 17 00:00:00 2001 From: Cedrick Cooke Date: Thu, 5 Sep 2024 11:41:15 -0700 Subject: [PATCH 5/7] Include database name in transaction open/close logs --- core/src/jsMain/kotlin/Database.kt | 16 ++++++++++------ 1 file changed, 10 insertions(+), 6 deletions(-) diff --git a/core/src/jsMain/kotlin/Database.kt b/core/src/jsMain/kotlin/Database.kt index 510d616..835c6d4 100644 --- a/core/src/jsMain/kotlin/Database.kt +++ b/core/src/jsMain/kotlin/Database.kt @@ -46,11 +46,11 @@ public suspend fun openDatabase( "Upgrading database `$name` from version `${versionChangeEvent.oldVersion}` to `${versionChangeEvent.newVersion}`" } val id = database.transactionId++ - logger.log(Type.Transaction) { "Opened versionchange transaction $id" } + logger.log(Type.Transaction) { "Opened versionchange transaction $id on database `$name`" } val transaction = VersionChangeTransaction(checkNotNull(request.transaction), logger, id) transaction.initialize(database, versionChangeEvent.oldVersion, versionChangeEvent.newVersion) transaction.awaitCompletion { event -> - logger.log(Type.Transaction, event) { "Closed versionchange transaction $id" } + logger.log(Type.Transaction, event) { "Closed versionchange transaction $id on database `$name`" } } } logger.log(Type.Database) { "Opened database `$name`" } @@ -115,10 +115,12 @@ public class Database internal constructor( id, ) - logger.log(Type.Transaction) { "Opened readonly transaction $id using stores ${store.joinToString { "`$it`" }}" } + logger.log(Type.Transaction) { + "Opened readonly transaction $id using stores ${store.joinToString { "`$it`" }} on database `$name`" + } val result = transaction.action() transaction.awaitCompletion { event -> - logger.log(Type.Transaction, event) { "Closed readonly transaction $id" } + logger.log(Type.Transaction, event) { "Closed readonly transaction $id on database `$name`" } } result } @@ -145,10 +147,12 @@ public class Database internal constructor( objectStore(store.first()).awaitTransaction() } - logger.log(Type.Transaction) { "Opened readwrite transaction $id" } + logger.log(Type.Transaction) { + "Opened readwrite transaction $id using stores ${store.joinToString { "`$it`" }} on database `$name`" + } val result = transaction.action() transaction.awaitCompletion { event -> - logger.log(Type.Transaction, event) { "Closed readwrite transaction $id" } + logger.log(Type.Transaction, event) { "Closed readwrite transaction $id on database `$name`" } } result } From df369bc55aa3819431d6db22b4238c53a33ad83c Mon Sep 17 00:00:00 2001 From: Cedrick Cooke Date: Thu, 5 Sep 2024 15:59:37 -0700 Subject: [PATCH 6/7] Transaction logging should happen before opening transaction --- core/src/jsMain/kotlin/Database.kt | 18 +++++++++--------- 1 file changed, 9 insertions(+), 9 deletions(-) diff --git a/core/src/jsMain/kotlin/Database.kt b/core/src/jsMain/kotlin/Database.kt index 835c6d4..a433d93 100644 --- a/core/src/jsMain/kotlin/Database.kt +++ b/core/src/jsMain/kotlin/Database.kt @@ -46,7 +46,7 @@ public suspend fun openDatabase( "Upgrading database `$name` from version `${versionChangeEvent.oldVersion}` to `${versionChangeEvent.newVersion}`" } val id = database.transactionId++ - logger.log(Type.Transaction) { "Opened versionchange transaction $id on database `$name`" } + logger.log(Type.Transaction) { "Opening versionchange transaction $id on database `$name`" } val transaction = VersionChangeTransaction(checkNotNull(request.transaction), logger, id) transaction.initialize(database, versionChangeEvent.oldVersion, versionChangeEvent.newVersion) transaction.awaitCompletion { event -> @@ -109,15 +109,15 @@ public class Database internal constructor( action: suspend Transaction.() -> T, ): T = withContext(Dispatchers.Unconfined) { val id = transactionId++ + logger.log(Type.Transaction) { + "Opened readonly transaction $id using stores ${store.joinToString { "`$it`" }} on database `$name`" + } + val transaction = Transaction( ensureDatabase().transaction(arrayOf(*store), "readonly", transactionOptions(durability)), logger, id, ) - - logger.log(Type.Transaction) { - "Opened readonly transaction $id using stores ${store.joinToString { "`$it`" }} on database `$name`" - } val result = transaction.action() transaction.awaitCompletion { event -> logger.log(Type.Transaction, event) { "Closed readonly transaction $id on database `$name`" } @@ -137,6 +137,10 @@ public class Database internal constructor( action: suspend WriteTransaction.() -> T, ): T = withContext(Dispatchers.Unconfined) { val id = transactionId++ + logger.log(Type.Transaction) { + "Opening readwrite transaction $id using stores ${store.joinToString { "`$it`" }} on database `$name`" + } + val transaction = WriteTransaction( ensureDatabase().transaction(arrayOf(*store), "readwrite", transactionOptions(durability)), logger, @@ -146,10 +150,6 @@ public class Database internal constructor( // Force overlapping transactions to not call `action` until prior transactions complete. objectStore(store.first()).awaitTransaction() } - - logger.log(Type.Transaction) { - "Opened readwrite transaction $id using stores ${store.joinToString { "`$it`" }} on database `$name`" - } val result = transaction.action() transaction.awaitCompletion { event -> logger.log(Type.Transaction, event) { "Closed readwrite transaction $id on database `$name`" } From 9535e3a93bd337ad335351bf2c99759d6047d926 Mon Sep 17 00:00:00 2001 From: Cedrick Cooke Date: Tue, 26 Nov 2024 10:57:46 -0800 Subject: [PATCH 7/7] Update khronicle to 0.5.0 --- gradle/libs.versions.toml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/gradle/libs.versions.toml b/gradle/libs.versions.toml index 4da6de4..1d92a97 100644 --- a/gradle/libs.versions.toml +++ b/gradle/libs.versions.toml @@ -4,7 +4,7 @@ kotlin = "2.0.21" [libraries] coroutines-core = { module = "org.jetbrains.kotlinx:kotlinx-coroutines-core", version.ref = "coroutines" } -khronicle-core = { module = "com.juul.khronicle:khronicle-core", version = "0.3.0" } +khronicle-core = { module = "com.juul.khronicle:khronicle-core", version = "0.5.0" } [plugins] dokka = { id = "org.jetbrains.dokka", version = "1.9.20" }