dexie / Dexie.js

A Minimalistic Wrapper for IndexedDB
https://dexie.org
Apache License 2.0
11.69k stars 641 forks source link

OpenFailedError: TransactionInactiveError when using indexeddbshim + dexie #1126

Closed jayaddison closed 4 years ago

jayaddison commented 4 years ago

I'm adding some database-related unit test coverage for a Dexie-powered browser application written in JavaScript+TypeScript.

Unit tests are executed via mochapack (webpack to compile the app followed by mocha test execution), and to provide the IndexedDB API methods, an in-memory indexeddbshim instance is injected at test runtime.

As a proof-of-concept I'd like to add a simple assertion on the output of Table.count for one of the database tables, and then build more complicated cases from there.

I'm running into the following error/exception -- and have enabled indexeddbshim's DEBUG option to provide a bit more context:

$ make tests
...
<snip>
...
Trying to fetch data for Index SELECT "value" FROM "S__sync^Nodes" WHERE "I_is^Master" NOT NULL AND "I_is^Master" = ? LIMIT 1 [ 'È-40110000000000' ]
TransactionInactiveError: A request was placed against a transaction which is currently not active, or which is finished. 
Trace: 
    at logError (/home/james/Documents/reciperadar/frontend/node_modules/indexeddbshim/src/DOMException.js:213:34)
    at createDOMException (/home/james/Documents/reciperadar/frontend/node_modules/indexeddbshim/src/DOMException.js:300:9)
    at Function.__assertActive (/home/james/Documents/reciperadar/frontend/node_modules/indexeddbshim/src/IDBTransaction.js:535:15)
    at IDBObjectStore.add (/home/james/Documents/reciperadar/frontend/node_modules/indexeddbshim/src/IDBObjectStore.js:506:20)
    at eval (webpack://%5Bname%5D/./node_modules/dexie/dist/dexie.mjs?:2952:44)
    at new Promise (<anonymous>)
    at Object.mutate (webpack://%5Bname%5D/./node_modules/dexie/dist/dexie.mjs?:2904:20)
    at Object.mutate (webpack://%5Bname%5D/./node_modules/dexie/dist/dexie.mjs?:3895:38)
    at eval (webpack://%5Bname%5D/./node_modules/dexie/dist/dexie.mjs?:1480:31)
    at checkTableInTransaction (webpack://%5Bname%5D/./node_modules/dexie/dist/dexie.mjs?:1342:20)
...
<snip>
...
  1 failing

  1) test
       load database state from document:
     OpenFailedError: TransactionInactiveError A request was placed against a transaction which is currently not active, or which is finished
 TransactionInactiveError: A request was placed against a transaction which is currently not active, or which is finished

I've had a look at https://github.com/dfahlander/Dexie.js/issues/712 and https://github.com/dfahlander/Dexie.js/issues/701#issuecomment-392756378 -- the latter mentions that Native async await can result in that a transaction is committed too early (which is also the case in Firefox. This is due to incompatiblity between IndexedDB(Shim) and the native Promise). Transpiled async await still fine. -- and I wonder if that could be relevant to the problem here.

I'd appreciate any assistance on how to investigate this further and any possible workarounds or fixes! I've been attempting some very basic debugging by editing the local node_modules directory copy of dexie and am glad to provide any other assistance figuring out the cause.

dfahlander commented 4 years ago

Have you tried to transpile the tests down to ES5? (this is to avoid the incompability between native promises and the original IndexedDB spec, which is used by IDBShim)

jayaddison commented 4 years ago

@dfahlander Targeting ES5 seems tricky; I'm running into some issues with more recent versions of TypeScript that seem to ignore/auto-include type definitions from ES6+ when I try to set compilerOptions.target to ES6 in tsconfig.json.

I think https://github.com/microsoft/TypeScript/issues/31649 is the same issue upstream. I'll try to figure out a bit more about what's going on here.

dfahlander commented 4 years ago

You can also avoid using async/await instead of transpiling the code. The problem is that await calls makes the code return to come back in a later tick, and at that time IndexedDBShim has started believing that the transaction isn't being used anymore. Dexie will patch the global Promise within transactions so that those microticks occur in an emulated major tick that ensures IDB doesn't throw away the transaction but this only works if using Promise.prototype.then() etc, not async/await. When using native async/await things happen deep down in the browser engine that is not possible to control.

jayaddison commented 4 years ago

Thanks @dfahlander - that makes sense. So the transpilation step is essentially introducing the use of the global Promise type, and then Dexie is able to patch that?

I do like the convenience (and developer experience) of using async/await in the codebase so I'll try to get the transpilation to ES5 working. It's nearly working, so hopefully I can resolve that today and then close this issue. If I don't manage to get it fixed within the next day or two, I think we can just trust that this issue is solvable and close this issue.

Out of interest do you know if it's a tractable problem to handle that tick behaviour in indexeddbshim, or whether any other mock IndexedDB libraries can handle that? (I'd be curious about the level of effort involved in applying a lower-level fix - I've seen one or two issues discussing similar items in the indexeddbshim repo)

jayaddison commented 4 years ago

Hrm. I do now believe I'm transpiling with ES5 as the target, and without pulling in any unnecessary type definitions (ensuring that node type definitions are not pulled in solves the problem described in https://github.com/microsoft/TypeScript/issues/31649).

I did encounter an error regarding a missing type declaration for Promise, which resulted in my inclusion of the es2015.promise lib.

The resulting tsconfig.json contains:

{
  "compilerOptions": {
    "allowJs": true,
    "lib": [ "es5", "es2015.promise" ],
    "moduleResolution": "node",
    "resolveJsonModule": true,
    "target": "es5",
    "types": ["jquery", "mocha"]
  },
  ...
}

However the OpenFailedError still occurs.

jayaddison commented 4 years ago

I think this is something to do with the unit test suite. I've noticed that this failure occurs in a particular test suite module that contains exactly two tests.

If I remove either one of the tests, then the OpenFailedError never occurs. So my hunch is that the test framework is causing the database to be 'opened' twice while the test module runs, and the second occurrence fails.

I'm going to close this with that finding, since it's enough of a discovery & workaround to allow me to continue.

jayaddison commented 4 years ago

Despite a previous attempted workaround, I ran into this issue again after in another database-related unit test. This time I figured it'd be worth adding console debugging to try to determine the root cause.

For reference, the test case I've been using writes a single record then performs a count on the table (expecting 1 total).

The error and stacktrace I've encountered for that test is:

OpenFailedError: TransactionInactiveError A request was placed against a transaction which is currently not active, or which is finished
 TransactionInactiveError: A request was placed against a transaction which is currently not active, or which is finished
      at Transaction$$1.Transaction.create (webpack://%5Bname%5D/./node_modules/dexie/dist/dexie.mjs?:2615:27)
      at tempTransaction (webpack://%5Bname%5D/./node_modules/dexie/dist/dexie.mjs?:1287:19)
      at eval (webpack://%5Bname%5D/./node_modules/dexie/dist/dexie.mjs?:1282:67)
      at eval (webpack://%5Bname%5D/./node_modules/dexie/dist/dexie.mjs?:1228:23)
      at callListener (webpack://%5Bname%5D/./node_modules/dexie/dist/dexie.mjs?:951:19)
      at endMicroTickScope (webpack://%5Bname%5D/./node_modules/dexie/dist/dexie.mjs?:1023:25)
      at handleRejection (webpack://%5Bname%5D/./node_modules/dexie/dist/dexie.mjs?:915:9)
      at eval (webpack://%5Bname%5D/./node_modules/dexie/dist/dexie.mjs?:1228:23)

By applying the changes illustrated in https://github.com/jayaddison/Dexie.js/commit/97b44c79262f01fe4d2a6a95cf6cd47eb8e7292e , I'm able to get the test to pass.

I'll try to spend a bit more time to figure out exactly what those changes affect and why that appears to remedy the problem; I'm including the commit here in case it helps spark any ideas, and for later reference.

Edit: update commit reference to point to fork repository, where it exists/originates

jayaddison commented 4 years ago

This may somehow be related to addons and/or dexie-observable:

PSD.letThrough = true -- assignment to a variable that was modified to allow tests to run in https://github.com/dfahlander/Dexie.js/commit/97b44c79262f01fe4d2a6a95cf6cd47eb8e7292e -- is being set by this line of code.

During test suite runs, that function is being called twice; the first time is during addon initialization at this line.

The second call occurrence is initiated within the indexeddbshim library, when it calls endMicrotickScope.

Removing the addons list allows unit tests to run to completion, so I'll begin by figuring out the behaviour around the first call; the PSD variable is a global, and letThrough is never unset, so it's possible that the second call may turn out to be less relevant.

jayaddison commented 4 years ago

Could it be a bug that letThrough is never unset?

One idea is that newScope -- which is essentially a wrapper for a fn function passed as an argument -- could be modified so that it undoes the changes it applies to the global PSD after the wrapped function returns.

This is illustrated as a commit by https://github.com/jayaddison/Dexie.js/commit/5711da31c3474c6c22caee6d80f53802b3bc9d37

Note that tests do not pass with this change alone. I think that something in dexie-observable's database ready event handling may somehow be causing a conflict at database open-time, tangentially-related to the letThrough change.

jayaddison commented 4 years ago

The conflict mentioned previously appears to occur while the dexie-observable database ready handler is adding itself as a sync node to the Dexie database.

The change in https://github.com/jayaddison/Dexie.js/commit/46a412563511f69c29469e668837c076eb40faf3 (removing the db._syncNodes.add operation) allows unit tests to pass.

I don't yet completely understand what's happening here. That operation occurs within a rw transaction on _syncNodes, so that part looks fine. Is the database open by that point?

jayaddison commented 4 years ago

Debugging the value of db._state.isBeingOpened before db._syncNodes.add in the handler seems to confirm that the database is still being opened when that add write operation is attempted.

Perhaps this is how the conflict occurs; the ready event triggers in the database shortly before it opens, and then dexie-observable uses a transaction that attempts to write to the database -- which will wait until the database is open. Conversely, the database cannot open until all addon event handlers are complete.

That's just a theory but might explain the behaviour?

jayaddison commented 4 years ago

Edits: s/deadlock/conflict in previous comments.. the process does finish, but fails due to TransactionInactiveError.

jayaddison commented 4 years ago

@dfahlander I think I've made some progress towards finding a root cause here, but it's still a bit approximate.

There's some kind of conflicting interaction between the Dexie-Observable addon initialization and Dexie core during opening of the database, particularly inside the ready hook.

The addon performs some transactional operations on the _syncNodes table during the startObserving function, and there is some invalid/incorrect re-use of a completed/committed transaction that leads to the TransactionInactiveError.

I'm not completely sure why this is surfaced by usage of indexeddbshim in particular, but your mention (and code comments) about ticks and transaction behaviour are I'd guess something to do with it.

1138 contains a potential fix that is 'working' here, although I'm not completely confident in it.

dfahlander commented 4 years ago

Thanks @jayaddison! I haven't had a chance to deep dive into this issue yet. Looking at the PR, it seems to be ok except for that the code that reads and puts syncNodes isn't atomic anymore. Is the issue gone if you changed to:


return Dexie.ignoreTransaction(() => db.transaction('rw', '_syncNodes', () => {
    ...
  })
);
?
dfahlander commented 4 years ago

@jayaddison I would like to deep dive into this (if/when get a little time over). Do you have any repro of the issue?

jayaddison commented 4 years ago

@dfahlander Thanks - and yep, https://github.com/jayaddison/dexie-1126-repro now contains a minimal repro case for this.

jayaddison commented 4 years ago

Looking at the PR, it seems to be ok except for that the code that reads and puts syncNodes isn't atomic anymore. Is the issue gone if you changed to: ... ...

Unfortunately not, nope - TransactionInactiveError occurs with that configuration too.

I also tried passing the ! and ? flags to the transaction mode parameter in case I could find a route through that way - they didn't seem to affect the result either.