AsyncQueue is already failed: The transaction was aborted, so the request cannot be fulfilled. #1642

larssn · 2019-03-27T17:02:26Z

Describe your environment

Operating System version: Android, so the version varies
Browser version: Usually latest Chrome (73.0.3683.90)
Firebase SDK version: 5.9.3
Firebase Product: Firestore

Describe the problem

We're seeing the following error more and more lately (via our error reporting service):

Error: Uncaught (in promise): Error: FIRESTORE (5.9.1) INTERNAL ASSERTION FAILED: AsyncQueue is already failed: The transaction was aborted, so the request cannot be fulfilled.
Error: FIRESTORE (5.9.1) INTERNAL ASSERTION FAILED: AsyncQueue is already failed: The transaction was aborted, so the request cannot be fulfilled.
    at fail (file:///android_asset/www/main.js:86695:11)
    at AsyncQueue.push../node_modules/@firebase/firestore/dist/index.cjs.js.AsyncQueue.verifyNotFailed (file:///android_asset/www/main.js:94221:13)
    at AsyncQueue.push../node_modules/@firebase/firestore/dist/index.cjs.js.AsyncQueue.enqueue (file:///android_asset/www/main.js:94173:14)
    at AsyncQueue.push../node_modules/@firebase/firestore/dist/index.cjs.js.AsyncQueue.enqueueAndForget (file:///android_asset/www/main.js:94165:14)
    at FirestoreClient.push../node_modules/@firebase/firestore/dist/index.cjs.js.FirestoreClient.listen (file:///android_asset/www/main.js:105490:25)
    at Query.push../node_modules/@firebase/firestore/dist/in...
  at fail(./node_modules/@firebase/firestore/dist/index.cjs.js:155:1)
  at AsyncQueue.push../node_modules/@firebase/firestore/dist/index.cjs.js.AsyncQueue.verifyNotFailed(./node_modules/@firebase/firestore/dist/index.cjs.js:7681:1)
  at AsyncQueue.push../node_modules/@firebase/firestore/dist/index.cjs.js.AsyncQueue.enqueue(./node_modules/@firebase/firestore/dist/index.cjs.js:7633:1)
  at AsyncQueue.push../node_modules/@firebase/firestore/dist/index.cjs.js.AsyncQueue.enqueueAndForget(./node_modules/@firebase/firestore/dist/index.cjs.js:7625:1)
  at FirestoreClient.push../node_modules/@firebase/firestore/dist/index.cjs.js.FirestoreClient.listen(./node_modules/@firebase/firestore/dist/index.cjs.js:18950:1)
  at Query.push../node_modules/@firebase/firestore/dist/index.cjs.js.Query.onSnapshotInternal(./node_modules/@firebase/firestore/dist/index.cjs.js:21167:1)
  at Query.push../node_modules/@firebase/firestore/dist/index.cjs.js.Query.onSnapshot(./node_modules/@firebase/firestore/dist/index.cjs.js:21148:1)
  at Observable._subscribe(./node_modules/@angular/fire/firestore/es2015/observable/fromRef.js:5:1)
...

This error is of a critical nature, as it entirely breaks the DB layer. Data stops getting written to the database, and it can be somewhat difficult to detect when the DB gets into this state, as the error is only thrown once. You can then call all the DB functions, and everything appears to work as normal, except no data ends up in the cloud (nor the persistence layer). (This was incorrect. Our error collection service just aggregated the data)

Steps to reproduce:

Apologies, but it's entirely periodic. It could be related to IndexedDB reaching a certain size, as clearing it out seems to postpone the problem for a few weeks. I have no theories as to what causes the "transaction to be aborted".

We were hoping the new garbage collection feature would take care of the problem, but so far it doesn't seem like it.

The devices running this are of the model "Samsung T580".

Any other info you need, let me know.

The text was updated successfully, but these errors were encountered:

mikelehen · 2019-03-27T21:46:27Z

@larssn Thanks for the report and sorry you're running into issues.

You said that clearing IndexedDB seems to postpone the problem and so you think it's size-related. Does that mean that just refreshing the browser (without clearing IndexedDB) does not help? Once the error happens, the problem continues to happen until you clear IndexedDB persistence? If so, that would definitely indicate this is a size issue. But I want to be clear. Thanks!

larssn · 2019-03-28T08:32:35Z

@mikelehen Refreshing the browser does fix the problem, but it always seem to be fairly temporary and we can expect to see the error again some hours later (it happened exactly like that yesterday). Clearing IDB causes the problem to go away for weeks until we reach a certain size level again.

I'm at a client right now, and they have 3 main devices, each of which has the following storage sizes:
Device 1: 66.09MB
Device 2: 63.23MB
Device 3: 77,57MB

The 60+ MB theshold seems to be the danger zone.

/Lars

Ps. We use sentry for error logging, and I can share the crash reports with you if you want? I can't post them here since they contain user information. But there might be valuable information to be found there.

PPs. We've set the garbage collection threshold to 5MB (we thought), so I'm suspecting that it's actually not turned on. It's hard to tell. We've enabled it as can be seen here: angular/angularfire#2030 but that's an entirely different issue that I don't want to pollute this issue with. So just ignore.

edit - updated numbers to exclude app size

LanderBeeuwsaert · 2019-03-28T10:18:38Z

I have a similar (but not the same) one, don't know if it better should have it's own ticket or not. Let me know if it's preferred to create a separate one.

Happened 2 times on +- 200 users the last 4 days.

larssn · 2019-03-28T11:07:26Z

@LanderBeeuwsaert I recall us having had that one as well, but less frequent.

mikelehen · 2019-03-28T20:54:30Z

@larssn Thanks for the update. I don't really understand why refreshing would make the error go away for a while if it's quota-related. That seems suspicious. Though I know Chrome at one point had a heuristic-based IndexedDb quota that was based on the amount of free space on the device, so in theory the quota could change from one run to the next.

If you want to verify that garbage collection is enabled, you can add firebase.firestore.setLogLevel('debug') and then look for a log message like "Garbage collection scheduled in 60000ms".

And if you are willing to do some more digging, it might be illuminating to try to intentionally reproduce a quota issue. E.g. use a device similar to what your users have seen this on, set the cacheSizeBytes threshold very high, and then perform lots of large (non-overlapping) queries to fill up the cache with lots of documents... and see if you can get this error to happen. Else I'll see if I can do something like this in the next few days.

larssn · 2019-03-29T12:43:33Z

Not sure if it's quota related, since inspecting the exact same Samsung model claims the storage quata is 727MB. Also the error thrown should be something like QuotaExceededError, as far as I've read.

I've looked at the AsyncQueue class, and I'm wondering why failures are persisted in the class:
AsyncQueue#failure
I'm sure there's reasoning behind it, it's just that any failure will make AsyncQueue fail forever going forward. Shouldn't it retry on every request, in case the error was transient?

So I tried reproducing the problem by downloading about 20000 orders (which are pretty big objects in our system), but nothing out of the ordinary happened. I'd set the GC to 500x1024x1024 beforehand, so that should be enough. I did notice that Chrome's IndexedDB metric seemed off, where GC would claim that size X was below the threshold to be GC'ed, and the Chrome metric would indicate a different size X for IDB.
There might be additional steps into creating the crash condition.

Ps. Thanks for the GC tip, I've verified that GC is indeed running as expected.

mikelehen · 2019-03-29T15:11:11Z

@larssn Thanks for the extra investigation! Bummer it didn't lead to a reproduction of the issue yet. :-/

Per your comments / question:

Our GC size calculation is very much an estimate since there's no API to determine the actual size the browser is using. So I'd expect the actual size to differ than the browser size, but it should hopefully be within a factor of ~3x or so.
In general the SDK isn't designed to tolerate IndexedDB failures. So if some operation of ours fails on the AsyncQueue, we can't safely retry it or skip it. Either one could lead to data corruption (your on-disk cache would end up inconsistent, leading to subsequent undefined behavior / crashes), and we try really hard to avoid that.

FWIW- This is the heuristic I was talking about that Chrome uses: https://chromium.googlesource.com/chromium/src/+/refs/heads/master/storage/browser/quota/quota_settings.cc#68

So I think maybe if you have 7GB free on the device, then the storage quota will be ~10% (700MB) but if you have much less space free, then the storage quota could get smaller. So it would be interesting to find out if users running into this are running out of space on their device in general.

But then again, maybe it's not quota-related at all. :-/

larssn · 2019-03-29T15:18:21Z

@mikelehen No problem. I really hope we find this one, as it is a pretty big stress factor that orders are getting dropped.

Regarding space, I know our users don't install much on the 3 devices I mentioned, as they are mounted to the wall - it's mainly meant for our app only.

Let me know if you want/need access to those crash logs at some point.

Thanks,
Lars

mikelehen · 2019-03-29T15:22:55Z

Oh! You're welcome to send me any crash logs you have (michael@firebase.com) and I'll take a look. I'm assuming it's mostly just the exception message / stacktrace that you pasted in the initial bug, but more than happy to look through for additional clues.

If we can somehow get the firebase.firestore.setLogLevel('debug') logs leading up to one of these crashes, I'd expect that to be a little more enlightening, but you can forward any info you have and I'll certainly take a look.

Thanks and sorry I don't have a better answer at this point!

larssn · 2019-03-29T15:39:39Z

Is there any way to make debug mode a little less verbose? Just worried that have 100k+ lines in a debug console will make chrome unhappy. It crashed with out of memory errors a few times today when I did a big data pull with debug mode turned on.

Ps. I've sent you a few mails regarding crash log access.

mikelehen · 2019-03-29T15:42:20Z

Thanks. I've received the crash log access. There isn't a direct way to make the logging less verbose.

One thing I've seen done in the past is hijack console.log and store a rolling in-memory buffer of the last 1000 lines or so, and then only actually log it if a problem occurs. Not sure if that would be an option for you.

larssn · 2019-03-29T15:53:41Z

I'm kinda swamped with work atm, but your idea is pretty good. I'll see if I can find time to implement it.

mikelehen · 2019-03-29T16:00:36Z

Sounds good. Alternatively if it's convenient to use a modified Firestore SDK, you could make the changes shown here: #1649

This will add more error-level logging (on by default) to the codepaths in question. In fact, this may be more helpful anyway, since the debug logging doesn't cover all of the abort cases.

One thing I'm trying to determine for certain is if the SDK is internally aborting the transaction, or if Chrome is doing it on its own.

sengoontoh · 2019-04-02T18:42:01Z

Interested in learning the outcome to this.

mikelehen · 2019-04-02T18:45:23Z

@sengoontoh We still don't have enough information to make headway on this issue. If you are experiencing it, please consider adding the logging I mention in #1642 (comment) and report back. Thanks!

sengoontoh · 2019-04-02T18:48:26Z

console.log's get optimized away in production release. Is there any way to pipe the debug logs into somewhere else?

mikelehen · 2019-04-02T19:05:55Z

@sengoontoh I think that would depend on your environment / build configuration (browsers certainly don't strip out console.log by default), so I don't think I can answer that without knowing how you're building / deploying, etc. Sorry.

ghost · 2019-04-09T12:52:32Z

I'm getting that error constantly, sadly never been able to reproduce it on my own, so far that storage limit might be the only logical explanation, so I guess the only way to fix it is disable offline persistence and handle updates via some timestamp...

larssn · 2019-04-13T08:11:46Z

@mikelehen So an AsynQueue error just came in. Still not much to go by, as far as I can tell.
The breadcrumbs look a bit odd for the error (I removed sensitive info):

"02:58:22" - GET https://firestore.googleapis.com/google.firestore.v1.Firestore/Listen/channel [0]
"02:58:23" - POST https://securetoken.googleapis.com/v1/token [200]
"02:58:26" - POST [Filtered] [200]
"07:14:14" - GET https://firestore.googleapis.com/google.firestore.v1.Firestore/Listen/channel [200]
-- Then the crashes
[2019-04-13T07:14:14.775Z]  @firebase/firestore: transaction onabort called TimeoutError: Transaction timed out due to inactivity.

What strikes me as odd, is the 4 hour gap between heartbeats (2:58 - 7:14). They normally seem to happen every minute, towards the channel endpoint? Could it be Android putting the device in standby, while it's in the middle of a transaction, before being able to finish?

The terminals do get very slow, the bigger indexeddb gets. Doing transactions will take more and more time as it gets bigger, which might cross some kind of timeout threshold?

Another weird thing is the first heartbeat in the list above seems to have returned 0 instead of 200, which is odd.

mikelehen · 2019-04-29T21:00:00Z

@sr1dh4r Thanks for the report. I don't suppose you can provide a way to reproduce this issue, can you? That would be really helpful.

Failing that, you could perhaps enable logging (firebase.firestore.setLogLevel('debug')) and then capture the logs leading up to the error and send them to me (michael@firebase.com)? Thanks!

sr1dh4r · 2019-04-30T13:17:15Z

@mikelehen Will do. I also realised couple of things if it helps ...

The issue exists in both the older and the newer versions so that goes out the window.
The issue is isolated to one "collection" alone. The other collections, I'm able to add and get while this issue exists (Maybe this is obvious but wasn't to me).
In case of the faulting "collection", I'm always writing to the database in a loop every minute (keep alive kind of thing). Removing that, I do not see the issue anymore.

sr1dh4r · 2019-04-30T13:58:16Z

@mikelehen webview.js.log

mikelehen · 2019-04-30T17:53:18Z

@sr1dh4r Thanks. The most notable thing in the log is that there's a 20 minute gap directly prior to the error starting, which suggests that the app was in the background, and this may have triggered the issue. There's a known issue with this happening on iOS 12.2 devices (#1670) but you said this is Android, correct? Can you provide the Android version info? And do you know if this happens on other devices as well? Thanks.

When this hits, firestore fails for the rest of the lift of the page and the page appears semi functional. Better to force reload and have an actual working page even though it's not a great user experience. See firebase/firebase-js-sdk#1642 for details.

sr1dh4r · 2019-05-01T05:08:45Z

@mikelehen Yes, Android 8.0.0 (it's a one plus 3 device) and mostly whenever I unlock a phone after a while so yes, must be sleep/background related. I may have noticed it in the chrome browser on mac os but I'm not so sure (I didn't pay attention to the issue initially). Will let you know in case I notice it in on any other device and/or if I can provide a simple way for you to reproduce the issue.

kogratte · 2019-05-22T08:08:20Z

I'm currently facing the same issue, or something very similar. Still trying to get some logs, bug custom logger seems to be not working.

 firebase.firestore.setLogLevel("debug");
       firebase.database.enableLogging(function(message) {
        console.log("[FIREBASE]", message);
      });

My custom console log is never called.

schmidt-sebastian · 2019-05-22T16:04:37Z

@kogratte Do you see the same stacktrace in your console? If you can, it would also help to know if it reproduces if you only use Firestore.

nVitius · 2019-06-05T17:41:14Z

We are facing some similar issues here. I have a session-recording software (LogRocket) running and have recorded a couple instances of this error.

I have added the extra logging and will report back when I know more. A cursory investigation shows that this happens occasionally when executing a Write action. The POST will succeed but a GET that is triggered at the same time will fail after several minutes. The error is finally triggered when the request returns as failed.

In the meantime, it would be helpful to have some way to catch this error and prompt the user to reload their page. As-is, the app will just stop syncing data and the user can continue doing their work unaware that they will lose it all after the session ends. Perhaps we could also have a way to force a re-sync of the IndexedDB.

larssn · 2019-06-05T17:58:09Z

@nVitius The error should be catchable. We basically have a try catch with a location.reload() hooked up to anything that resembles this error.

VictorNorman · 2019-06-13T12:26:09Z

Another datapoint:

[log] - trail-summary-card: going to trail page now!
⚡️ [log] - stepInfoS.loadAllData: top, trailId 201
⚡️ [log] - trail-summary-card: going to trail page now!
APP INACTIVE
2019-06-13 14:09:39.422091+0200 App[341:40944] [ProcessSuspension] Background task expired while holding WebKit ProcessAssertion (isMainThread? 1).
2019-06-13 14:09:40.471503+0200 App[341:40944] [IPC] Connection::waitForSyncReply: Timed-out while waiting for reply, id = 296
⚡️ [error] - [2019-06-13T12:09:47.357Z] @firebase/firestore: Firestore (5.11.0): INTERNAL UNHANDLED ERROR: objectStore@[native code]
store@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:133684
verifyPrimaryLease@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:167072
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:166588
wrapUserFunction@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121957
nextCallback@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121735
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121291
onsuccess@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:136080
z@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:18490
runTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:2981
invokeTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:8879
m@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22324
k@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22549
⚡️ [error] - Unhandled Promise rejection: Failed to execute 'objectStore' on 'IDBTransaction': The transaction finished. ; Zone: ; Task: Promise.then ; Value: {"line":1,"column":133684,"sourceURL":"capacitor://localhost/main.7de908c3db3344dc8c7d.js"} objectStore@[native code]
store@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:133684
verifyPrimaryLease@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:167072
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:166588
wrapUserFunction@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121957
nextCallback@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121735
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121291
onsuccess@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:136080
z@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:18490
runTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:2981
invokeTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:8879
m@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22324
k@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22549
⚡️ [error] - [2019-06-13T12:09:47.370Z] @firebase/firestore: Firestore (5.11.0): FIRESTORE (5.11.0) INTERNAL ASSERTION FAILED: AsyncQueue is already failed: objectStore@[native code]
store@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:133684
verifyPrimaryLease@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:167072
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:166588
wrapUserFunction@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121957
nextCallback@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121735
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121291
onsuccess@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:136080
z@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:18490
runTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:2981
invokeTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:8879
m@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22324
k@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22549

⚡️ ------ STARTUP JS ERROR ------

⚡️ Error: FIRESTORE (5.11.0) INTERNAL ASSERTION FAILED: AsyncQueue is already failed: objectStore@[native code]
store@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:133684
verifyPrimaryLease@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:167072
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:166588
wrapUserFunction@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121957
nextCallback@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121735
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121291
onsuccess@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:136080
z@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:18490
runTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:2981
invokeTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:8879
m@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22324
k@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22549
⚡️ URL: capacitor://localhost/main.7de908c3db3344dc8c7d.js
⚡️ [error] - {"line":1,"column":18344,"sourceURL":"capacitor://localhost/main.7de908c3db3344dc8c7d.js"}
⚡️ main.7de908c3db3344dc8c7d.js:1:18347

⚡️ See above for help with debugging blank-screen issues
⚡️ [error] - {"line":1,"column":18344,"sourceURL":"capacitor://localhost/main.7de908c3db3344dc8c7d.js"}
APP ACTIVE
⚡️ [error] - {"line":1,"column":133684,"sourceURL":"capacitor://localhost/main.7de908c3db3344dc8c7d.js"}
⚡️ [error] - {"line":1,"column":133684,"sourceURL":"capacitor://localhost/main.7de908c3db3344dc8c7d.js"}

⚡️ ------ STARTUP JS ERROR ------

⚡️ InvalidStateError: Failed to execute 'objectStore' on 'IDBTransaction': The transaction finished.
⚡️ URL: capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js
⚡️ polyfills.2ec9b9c4a8011ded8941.js:1:3052

⚡️ See above for help with debugging blank-screen issues
⚡️ [error] - [2019-06-13T12:09:47.991Z] @firebase/firestore: Firestore (5.11.0): FIRESTORE (5.11.0) INTERNAL ASSERTION FAILED: AsyncQueue is already failed: objectStore@[native code]
store@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:133684
verifyPrimaryLease@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:167072
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:166588
wrapUserFunction@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121957
nextCallback@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121735
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121291
onsuccess@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:136080
z@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:18490
runTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:2981
invokeTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:8879
m@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22324
k@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22549
⚡️ [error] - ERROR {"line":1,"column":18344,"sourceURL":"capacitor://localhost/main.7de908c3db3344dc8c7d.js"}
⚡️ To Native -> Clipboard write 69799135
2019-06-13 14:12:17.419301+0200 App[341:44493] Returning local object of class NSString
⚡️ TO JS {}
⚡️ To Native -> Clipboard write 69799136
2019-06-13 14:12:18.489525+0200 App[341:44669] Returning local object of class NSString
⚡️ TO JS {}
2019-06-13 14:12:18.508497+0200 App[341:44493] PBItemCollectionServicer connection disconnected.
⚡️ To Native -> Clipboard write 69799137
2019-06-13 14:12:19.037230+0200 App[341:44679] Returning local object of class NSString
⚡️ TO JS {}
2019-06-13 14:12:19.059413+0200 App[341:44679] PBItemCollectionServicer connection disconnected.
⚡️ To Native -> Clipboard write 69799138
2019-06-13 14:12:19.304941+0200 App[341:44669] Returning local object of class NSString
⚡️ TO JS {}
2019-06-13 14:12:19.325909+0200 App[341:44493] PBItemCollectionServicer connection disconnected.
⚡️ To Native -> Clipboard write 69799139
2019-06-13 14:12:19.543223+0200 App[341:44679] Returning local object of class NSString
⚡️ TO JS {}
2019-06-13 14:12:19.564163+0200 App[341:44679] PBItemCollectionServicer connection disconnected.
⚡️ To Native -> Clipboard write 69799140
2019-06-13 14:12:19.722445+0200 App[341:44669] Returning local object of class NSString
⚡️ TO JS {}
2019-06-13 14:12:19.743270+0200 App[341:44493] PBItemCollectionServicer connection disconnected.
⚡️ [log] - stepInfoS.loadAllData: top, trailId 201
⚡️ [error] - [2019-06-13T12:12:24.273Z] @firebase/firestore: Firestore (5.11.0): FIRESTORE (5.11.0) INTERNAL ASSERTION FAILED: AsyncQueue is already failed: objectStore@[native code]
store@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:133684
verifyPrimaryLease@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:167072
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:166588
wrapUserFunction@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121957
nextCallback@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121735
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121291
onsuccess@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:136080
z@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:18490
runTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:2981
invokeTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:8879
m@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22324
k@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22549
⚡️ [error] - ERROR {"line":1,"column":18344,"sourceURL":"capacitor://localhost/main.7de908c3db3344dc8c7d.js"}
APP INACTIVE
⚡️ [error] - [2019-06-13T12:12:47.894Z] @firebase/firestore: Firestore (5.11.0): FIRESTORE (5.11.0) INTERNAL ASSERTION FAILED: AsyncQueue is already failed: objectStore@[native code]
store@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:133684
verifyPrimaryLease@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:167072
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:166588
wrapUserFunction@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121957
nextCallback@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121735
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121291
onsuccess@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:136080
z@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:18490
runTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:2981
invokeTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:8879
m@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22324
k@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22549
⚡️ [error] - {"line":1,"column":18344,"sourceURL":"capacitor://localhost/main.7de908c3db3344dc8c7d.js"}
⚡️ [error] - {"line":1,"column":18344,"sourceURL":"capacitor://localhost/main.7de908c3db3344dc8c7d.js"}

⚡️ ------ STARTUP JS ERROR ------

⚡️ Error: FIRESTORE (5.11.0) INTERNAL ASSERTION FAILED: AsyncQueue is already failed: objectStore@[native code]
store@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:133684
verifyPrimaryLease@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:167072
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:166588
wrapUserFunction@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121957
nextCallback@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121735
capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:121291
onsuccess@capacitor://localhost/main.7de908c3db3344dc8c7d.js:1:136080
z@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:18490
runTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:2981
invokeTask@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:8879
m@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22324
k@capacitor://localhost/polyfills.2ec9b9c4a8011ded8941.js:1:22549
⚡️ URL: capacitor://localhost/main.7de908c3db3344dc8c7d.js
⚡️ main.7de908c3db3344dc8c7d.js:1:18347

⚡️ See above for help with debugging blank-screen issues

Seen on iPhone iOS 12.3.1.

nVitius · 2019-06-13T13:19:16Z

I've had two users have this issue with Chrome on a MacBook Pro this past week. Unfortunately, the verbose logging hadn't been deployed to them yet. Will report back if I see it happen again.

kogratte · 2019-06-13T13:25:14Z

I currently have the following stacktrace:
v@https://localhost/main.55e215e7422172761e37.js:1:24433 verifyNotFailed@https://localhost/main.55e215e7422172761e37.js:1:123440 enqueue@https://localhost/main.55e215e7422172761e37.js:1:122646 enqueueAndForget@https://localhost/main.55e215e7422172761e37.js:1:122578 https://localhost/main.55e215e7422172761e37.js:1:219676 https://localhost/main.55e215e7422172761e37.js:1:218792 callOnClose@https://localhost/main.55e215e7422172761e37.js:1:115255 https://localhost/main.55e215e7422172761e37.js:1:118728 https://localhost/main.55e215e7422172761e37.js:1:118376 St@https://localhost/main.55e215e7422172761e37.js:1:1389114 dispatchEvent@https://localhost/main.55e215e7422172761e37.js:1:1389953 ta@https://localhost/main.55e215e7422172761e37.js:1:1419296 Yn@https://localhost/main.55e215e7422172761e37.js:1:1410698 na@https://localhost/main.55e215e7422172761e37.js:1:1417826 Ee@https://localhost/main.55e215e7422172761e37.js:1:1395139 Ka@https://localhost/main.55e215e7422172761e37.js:1:1397365 eb@https://localhost/main.55e215e7422172761e37.js:1:1396677 St@https://localhost/main.55e215e7422172761e37.js:1:1389114 dispatchEvent@https://localhost/main.55e215e7422172761e37.js:1:1389953 xn@https://localhost/main.55e215e7422172761e37.js:1:1406294 $a@https://localhost/main.55e215e7422172761e37.js:1:1414336 Fa@https://localhost/main.55e215e7422172761e37.js:1:1414313 [native code] z@https://localhost/polyfills.8bbb231b43165d65d357.js:1:18489 runTask@https://localhost/polyfills.8bbb231b43165d65d357.js:1:2980 invokeTask@https://localhost/polyfills.8bbb231b43165d65d357.js:1:8878 m@https://localhost/polyfills.8bbb231b43165d65d357.js:1:22323 k@https://localhost/polyfills.8bbb231b43165d65d357.js:1:22621

sengoontoh · 2019-06-16T20:46:47Z

Any updates this issue?

mikelehen · 2019-06-17T15:27:21Z

This issue is still unfortunately not really actionable since we have no way to reproduce it and no leads on what's causing it. It would help if people experiencing an issue could:

Report the exact error / stack trace they are seeing (since there have been a variety of different errors mentioned in this github issue).
Provide the device / OS / browser version on which the error occurred.
If at all possible, collect debug logs leading up to the error via firebase.firestore.setLogLevel('debug').
Provide any context about what the app was doing when the error occurred. For instance, from some of the reports, this seems to be related to the app being in the background for some period of time and then returning to the foreground. Confirming this and what devices it occurs on may help us develop a way to reproduce.

sengoontoh · 2019-06-17T15:49:33Z

What about the trace provided by @VictorNorman is that sufficient data?
@VictorNorman can you help provide more context? I would chip in but I'm only seeing this out in the field and have not been able to replicate internally.

mikelehen · 2019-06-17T15:55:30Z

@sengoontoh Not sure. It doesn't include anything leading up to the error which might have provided a clue as to what's triggering it (and verify that we're catching the root issue rather than a downstream issue). Since it's on iOS 12.3.1 it could be a manifestation of #1670 which will apparently be fixed in iOS 13.

nVitius · 2019-06-28T18:02:53Z

@mikelehen We deployed our app this week to about 90 users for acceptance testing. I had a hard time reproducing this issue myself, but I was able to capture a session of a user that saw this bug.
We use a plugin called LogRocket that watches for DOM changes and records them along with the contents of console and the network requests for that session. I would like to share this data with you, as I think it would have a lot of value in tracking this down.

mikelehen · 2019-06-28T18:06:39Z

@nVitius Sounds good. You can email it to me at michael@firebase.com.

scottfr · 2019-07-05T12:51:48Z

Here are some stack traces from my Chrome extension (Web SDK):

Error: FIRESTORE (5.8.4) INTERNAL ASSERTION FAILED: AsyncQueue is already failed: The transaction was aborted, so the request cannot be fulfilled.
  at fail(../firestore/dist/index.esm.js:149:11)
  at verifyNotFailed(../firestore/dist/index.esm.js:7450:13)
  at enqueue(../firestore/dist/index.esm.js:7402:14)
  at enqueueAndForget(../firestore/dist/index.esm.js:7394:14)
  at changeListener(../firestore/dist/index.esm.js:18136:34)
  at Array.tokenListener(../firestore/dist/index.esm.js:18675:23)
  at Kc(/resources/firebase-auth.js:1:131494)
  at Pc.e.bc(/resources/firebase-auth.js:1:135918)
  at Ce(/resources/firebase-auth.js:1:18085)
  at Gu.Pe.dispatchEvent(/resources/firebase-auth.js:1:19972)
  at ? (/resources/firebase-auth.js:1:120596)
  at r.g(/resources/firebase-auth.js:1:8788)
  at Ct(/resources/firebase-auth.js:1:9830)
  at Rt(/resources/firebase-auth.js:1:9721)
  at vt.e.Yb(/resources/firebase-auth.js:1:10524)
  at pt(/resources/firebase-auth.js:1:7614)

  Error: FIRESTORE (5.8.4) INTERNAL ASSERTION FAILED: AsyncQueue is already failed: The transaction was aborted, so the request cannot be fulfilled.
    at fail(../firestore/dist/index.esm.js:149:11)
    at verifyNotFailed(../firestore/dist/index.esm.js:7450:13)
    at enqueue(../firestore/dist/index.esm.js:7402:14)
    at enqueueAndForget(../firestore/dist/index.esm.js:7394:14)
    at dispatchIfNotClosed(../firestore/dist/index.esm.js:14315:25)
    at wrappedOnClose(../firestore/dist/index.esm.js:14271:13)
    at callOnClose(../firestore/dist/index.esm.js:6775:14)
    at fn(../firestore/dist/index.esm.js:7013:30)
    at call(../firestore/dist/index.esm.js:6988:21)
    at Lb(../webchannel-wrapper/dist/index.esm.js:25:201)
    at dispatchEvent(../webchannel-wrapper/dist/index.esm.js:23:356)
    at td(../webchannel-wrapper/dist/index.esm.js:113:111)
    at cg(../webchannel-wrapper/dist/index.esm.js:106:471)
    at sa(../webchannel-wrapper/dist/index.esm.js:106:258)
    at Tc(../webchannel-wrapper/dist/index.esm.js:103:140)
    at Kb(../webchannel-wrapper/dist/index.esm.js:51:46)
    at hg(../webchannel-wrapper/dist/index.esm.js:45:470)
    at Me(../webchannel-wrapper/dist/index.esm.js:43:160)
    at call(../webchannel-wrapper/dist/index.esm.js:43:116)
    at Lb(../webchannel-wrapper/dist/index.esm.js:25:201)
    at dispatchEvent(../webchannel-wrapper/dist/index.esm.js:23:356)
    at se(../webchannel-wrapper/dist/index.esm.js:80:220)
    at eg(../webchannel-wrapper/dist/index.esm.js:79:425)
    at apply(../webchannel-wrapper/dist/index.esm.js:79:396)
    at XMLHttpRequest.n(../node_modules/@sentry/browser/esm/helpers.js:83:1)

arthabus · 2019-07-30T09:38:35Z

Happens for me from time to time in a web app we are working on. It is still in development and if I leave a tab with the app open overnight sometimes it throws the error in console (using Chrome if that's of any help).
Also we have persistence enabled if that makes any difference.
Refreshing the tab fixes it, but till then the app can't do anything related to firebase.

Uncaught (in promise) Error: FIRESTORE (5.11.0) INTERNAL ASSERTION FAILED: AsyncQueue is already failed: Transaction timed out due to inactivity.
at g (chunk-vendors.2d9e867d.js:891)
at e.verifyNotFailed (chunk-vendors.2d9e867d.js:1198)
at e.enqueue (chunk-vendors.2d9e867d.js:1198)
at e.enqueueAndForget (chunk-vendors.2d9e867d.js:1198)
at e.listen (chunk-vendors.2d9e867d.js:1424)
at e.onSnapshotInternal (chunk-vendors.2d9e867d.js:1504)
at e.onSnapshot (chunk-vendors.2d9e867d.js:1504)
at app.a401670c.js:1
at new Promise ()
at new t (chunk-vendors.2d9e867d.js:540)

mikelehen · 2019-07-30T15:57:47Z

@arthabus Is this a laptop or a computer that goes to "sleep" when idle? There's a known issue in Chrome (see #939 and https://bugs.chromium.org/p/chromium/issues/detail?id=855624) that is likely to blame. :-/ Consider commenting on the chromium issue, especially if you have a concrete way to reproduce this. Thanks!

victjam · 2019-08-30T15:32:08Z

Any updates about this problem?

masterDoomX · 2019-08-31T20:25:20Z

I am also interested in

mikelehen · 2019-09-03T15:53:15Z

There is no update on this issue since it does not actually track any specific, actionable issue (see my comment from April). So I am closing it.

Going forward, if you are encountering:

An internal error was encountered in the Indexed Database server on iOS, please see here
TimeoutError: Transaction timed out due to inactivity. Please see here
Anything else. Please open a new issue, with full error details, logs (firebase.firestore.setLogLevel('debug')), and repro instructions so we can investigate.

Thanks!

google-oss-bot added the api: firestore label Mar 27, 2019

mikelehen added the needs-info label Mar 27, 2019

google-oss-bot added needs-attention and removed needs-info labels Mar 28, 2019

mikelehen self-assigned this Mar 28, 2019

mikelehen mentioned this issue Mar 29, 2019

[DO NOT SUBMIT] Add more logging to abort. #1649

Closed

mikelehen removed their assignment Apr 2, 2019

mikelehen added needs-info and removed needs-attention labels Apr 2, 2019

google-oss-bot added needs-attention and removed needs-info labels Apr 13, 2019

var-const mentioned this issue May 1, 2019

Uncaught exception in verifyNotFailed (Javascript, mostly iOS 12.2) #1733

Closed

mikelehen mentioned this issue Sep 3, 2019

Firestore encounters "TimeoutError: Transaction timed out due to inactivity." after laptop recovers from sleep. #2136

Closed

mikelehen closed this as completed Sep 3, 2019

schmidt-sebastian mentioned this issue Oct 3, 2019

Firestore: Attempt to get a record without an in-progress transaction #2232

Closed

firebase locked and limited conversation to collaborators Oct 12, 2019

AsyncQueue is already failed: The transaction was aborted, so the request cannot be fulfilled. #1642

AsyncQueue is already failed: The transaction was aborted, so the request cannot be fulfilled. #1642

Comments

larssn commented Mar 27, 2019 • edited Loading

Describe your environment

Describe the problem

Steps to reproduce:

mikelehen commented Mar 27, 2019

larssn commented Mar 28, 2019 • edited Loading

LanderBeeuwsaert commented Mar 28, 2019

larssn commented Mar 28, 2019

mikelehen commented Mar 28, 2019

larssn commented Mar 29, 2019 • edited Loading

mikelehen commented Mar 29, 2019

larssn commented Mar 29, 2019

mikelehen commented Mar 29, 2019

larssn commented Mar 29, 2019 • edited Loading

mikelehen commented Mar 29, 2019

larssn commented Mar 29, 2019

mikelehen commented Mar 29, 2019

sengoontoh commented Apr 2, 2019

mikelehen commented Apr 2, 2019

sengoontoh commented Apr 2, 2019

mikelehen commented Apr 2, 2019

ghost commented Apr 9, 2019

larssn commented Apr 13, 2019 • edited Loading

mikelehen commented Apr 29, 2019

sr1dh4r commented Apr 30, 2019

sr1dh4r commented Apr 30, 2019

mikelehen commented Apr 30, 2019

sr1dh4r commented May 1, 2019

kogratte commented May 22, 2019

schmidt-sebastian commented May 22, 2019

nVitius commented Jun 5, 2019 • edited Loading

larssn commented Jun 5, 2019

VictorNorman commented Jun 13, 2019

nVitius commented Jun 13, 2019

kogratte commented Jun 13, 2019 • edited Loading

sengoontoh commented Jun 16, 2019

mikelehen commented Jun 17, 2019

sengoontoh commented Jun 17, 2019

mikelehen commented Jun 17, 2019

nVitius commented Jun 28, 2019 • edited Loading

mikelehen commented Jun 28, 2019

scottfr commented Jul 5, 2019

arthabus commented Jul 30, 2019 • edited Loading

mikelehen commented Jul 30, 2019

victjam commented Aug 30, 2019

masterDoomX commented Aug 31, 2019

mikelehen commented Sep 3, 2019

larssn commented Mar 27, 2019 •

edited

Loading

larssn commented Mar 28, 2019 •

edited

Loading

larssn commented Mar 29, 2019 •

edited

Loading

larssn commented Mar 29, 2019 •

edited

Loading

larssn commented Apr 13, 2019 •

edited

Loading

nVitius commented Jun 5, 2019 •

edited

Loading

kogratte commented Jun 13, 2019 •

edited

Loading

nVitius commented Jun 28, 2019 •

edited

Loading

arthabus commented Jul 30, 2019 •

edited

Loading